It failed few times on CI [1], and it seems that 200ms is not enough:
2021.09.26 02:43:16.063992 [ 706 ] {d5144a51-f217-48f9-8630-29492f81aae5} <Trace> ContextAccess (default): Access granted: INSERT(id, s) ON test_fptde5.async_inserts
2021.09.26 02:43:16.069188 [ 706 ] {d5144a51-f217-48f9-8630-29492f81aae5} <Trace> AsynchronousInsertQueue: Have 1 pending inserts with total 11 bytes of data for query 'INSERT INTO test_fptde5.async_inserts FORMAT CSV'
2021.09.26 02:43:16.209661 [ 1940 ] {} <Trace> DynamicQueryHandler: Request URI: /?database=test_fptde5&log_comment=/usr/share/clickhouse-test/queries/0_stateless/02015_async_inserts_2.sh&async_insert=1&wait_for_async_insert=1
2021.09.26 02:43:16.340496 [ 1938 ] {e01d640f-90a8-4306-808f-d732fb144a11} <Trace> ContextAccess (default): Access granted: INSERT(id, s) ON test_fptde5.async_inserts
2021.09.26 02:43:16.401966 [ 1938 ] {e01d640f-90a8-4306-808f-d732fb144a11} <Trace> AsynchronousInsertQueue: Have 1 pending inserts with total 11 bytes of data for query 'INSERT INTO test_fptde5.async_inserts FORMAT CSV'
2021.09.26 02:43:16.667513 [ 1940 ] {5c059e03-397f-4f9a-95ca-0fcb3c479235} <Trace> ContextAccess (default): Access granted: INSERT(id, s) ON test_fptde5.async_inserts
2021.09.26 02:43:16.707577 [ 1392 ] {} <Error> AsynchronousInsertQueue: Failed parsing for query 'INSERT INTO test_fptde5.async_inserts FORMAT CSV' with query id d5144a51-f217-48f9-8630-29492f81aae5. DB::ParsingException: Cannot parse input: expected ','
before: 'qqqqqqqqqqq':
2021.09.26 02:43:16.789697 [ 1392 ] {} <Information> AsynchronousInsertQueue: Flushed 0 rows, 0 bytes for query 'INSERT INTO test_fptde5.async_inserts FORMAT CSV'
2021.09.26 02:43:16.872731 [ 1940 ] {5c059e03-397f-4f9a-95ca-0fcb3c479235} <Trace> AsynchronousInsertQueue: Have 1 pending inserts with total 11 bytes of data for query 'INSERT INTO test_fptde5.async_inserts FORMAT CSV'
2021.09.26 02:43:17.472223 [ 1392 ] {} <Trace> test_fptde5.async_inserts (b877377f-9706-488b-b877-377f9706f88b): Renaming temporary part tmp_insert_all_1_1_0 to all_1_1_0.
2021.09.26 02:43:17.527828 [ 1392 ] {} <Information> AsynchronousInsertQueue: Flushed 2 rows, 28 bytes for query 'INSERT INTO test_fptde5.async_inserts FORMAT CSV'
2021.09.26 02:43:18.344135 [ 1859 ] {} <Trace> test_fptde5.async_inserts (b877377f-9706-488b-b877-377f9706f88b): Renaming temporary part tmp_insert_all_2_2_0 to all_2_2_0.
2021.09.26 02:43:18.373230 [ 1859 ] {} <Information> AsynchronousInsertQueue: Flushed 2 rows, 28 bytes for query 'INSERT INTO test_fptde5.async_inserts FORMAT CSV'
[1]: https://clickhouse-test-reports.s3.yandex.net/29364/fb584715e175fef3a4c4373d1bbcebecab1db6d8/functional_stateless_tests_(thread).html#fail1
Which logs all the info about LogIn, LogOut and LogIn Failure events.
Additional info that is logged:
- User name
- event type (LogIn, LogOut, LoginFailure)
- Event date\time\time with microseconds
- authentication type (same as for IDENTIFIED BY of CREATE USER statement)
- array of active settings profiles upon login
- array of active roles upon login
- array of changed settings with corresponding values
- client address and port
- interface (TCP\HTTP\MySQL\PostgreSQL, etc.)
- client info (name, version info)
- optional LoginFailure reason text message.
Added some tests to verify that events are properly saved with all necessary info via following interfaces:
- TCP
- HTTP
- MySQL
Known limitations
- Not tested against named HTTP sessions, PostgreSQL and gRPC, hence those are not guaranteed to work 100% properly.