[osquery 5.12] Incorrect error handling by osquery when two tables of the same name are installed

[zayhanlon]

osquery issue: https://github.com/osquery/osquery/issues/8254

Fleet version: <!-- Copy this from the "My account" page in the Fleet UI, or run fleetctl --version --> 4.39

Web browser and operating system: Chrome

---

💥  Actual behavior

When two tables of the same name are installed, osquery provides an unhelpful error where it 'doesnt know what to do and selects a table at random'. There's a collision between the two and renders some tables unusable.

I have not been able to reproduce this but the customer reported it to me on a call. Please see the call recording and meeting notes for more context:

Snippet: https://us-65885.app.gong.io/call?id=5578130264448480852&highlights=%5B%7B%22type%22%3A%22SHARE%22%2C%22from%22%3A563%2C%22to%22%3A668%7D%5D

Notes: https://docs.google.com/document/d/1FOHCy37m5vO1UbJc2ZQQKy9Ws37GGV6YGTZrUYAVPKg/edit (item 7)

🧑‍💻  Steps to reproduce

Reproduce with the osquery-go example extension: https://github.com/osquery/osquery-go/blob/master/examples/table/main.go#L41

Copy-paste line 41 to try to register the same table twice in the extension.

Change line 41 to the name of a built-in osquery table (eg. time).

🕯️ More info (optional)

N/A

🛠️ To fix

Step 1:

• [x] Reproduce the conflicting table names scenario by adding an extension w/ two tables that have the same name
• [x] Share the error message in #g-endpoint-ops and tag @noahtalerman so we can decide if we want to improve the error message.

Step 2:

• [ ] If we decide that the error message could be improved, update make a change to error message: "Could not load the table name table from the extension name extension. This table's name conflicts with another table."
  • osquery PR: https://github.com/osquery/osquery/pull/8260

[sabrinabuckets]

Given Zay's inability to reproduce, and Mike's suggested resolution, I think it makes sense for us to include validation that would prevent the installation of a duplicate table name.

@noahtalerman does this need product/design input on the language of the error message, or are you comfortable with an engineer just tackling this?

[sharon-fdm]

Timebox investigation for returning this error: 3pts

[noahtalerman]

I think this one needs a quick drafting to figure out error message copy.

@rachaelshaw heads up, I assigned you this bug and added the product label.

[noahtalerman]

cc @sharon-fdm ^^

[rachaelshaw]

@zwass if osquery fails to start, does fleetd still start? Do you think we can make this change to the osquery behavior (in description)?

[noahtalerman]

Hey @zwass, regarding Rachael's comment above, should we open a bug report in osquery to address the error message for the table name collision?

[zwass]

Yes. IIRC though, osquery does reject duplicate table names.

[zwass]

Probably easy to reproduce with the osquery-go example extension: https://github.com/osquery/osquery-go/blob/master/examples/table/main.go#L41

Copy-paste line 41 to try to register the same table twice in the extension.

Change line 41 to the name of a built-in osquery table (eg. time).

[noahtalerman]

@sharon-fdm heads up, adding this bug back to the release board. We updated the reproduction steps and the "to fix" section in this issue.

[sharon-fdm]

@noahtalerman Got it. So to put it in simple words, the table that exists will be allowed to keep working, and any second table with the same name will not be loaded and will trigger the relevant error.

[noahtalerman]

the table that exists will be allowed to keep working, and any second table with the same name will not be loaded and will trigger the relevant error.

@sharon-fdm that's right. And, we want to make sure that the relevant error message is a good one.

[getvictor]

@noahtalerman TLDR: osquery prints warnings when trying to install two tables of the same name. This warning can be escalated to an error with --extensions_require flag. However, in either case, osquery will continue running.

When duplicating an osquery core table, osquery goes into an infinite loop printing the following warnings:

W0122 08:09:20.127226 1870475264 interface.cpp:143] Could not add extension example_extension: Duplicate registry item: time
2024/01/22 08:09:20 status 1 deregistering extension: No extension UUID found
W0122 08:09:22.806232 1868754944 watcher.cpp:738] Extension respawning too quickly: /Users/victor/work/fleet/example_table

When duplicating a table in 2 extensions, osquery goes into an infinite loop, printing the same warnings:

W0122 08:35:05.001511 1806512128 interface.cpp:143] Could not add extension example_extension2: Duplicate registry item: example_table
2024/01/22 08:35:05 status 1 deregistering extension: No extension UUID found
W0122 08:35:07.503100 1804218368 watcher.cpp:738] Extension respawning too quickly: /Users/victor/work/fleet/example_table2.ext

When duplicating the extension name, osquery goes into an infinite loop printing:

W0122 08:48:45.723423 1864888320 interface.cpp:114] Refusing to register duplicate extension example_extension
2024/01/22 08:48:45 status 1 deregistering extension: No extension UUID found
W0122 08:48:48.370070 1862594560 watcher.cpp:738] Extension respawning too quickly: /Users/victor/work/fleet/example_table2.ext

When using --extensions_require, osquery prints additional errors, but continues running:

> ./build/osquery/osqueryi --extensions_autoload=/Users/victor/work/fleet/extensions.load --extensions_require=example_extension,example_extension2
E0122 09:02:26.658702 1843982336 virtual_table.cpp:1115] Error creating named virtual table: example_table (1)
W0122 09:02:26.658733 1843982336 interface.cpp:143] Could not add extension example_extension2: SQLITE_ERROR
2024/01/22 09:02:26 status 1 deregistering extension: No extension UUID found
W0122 09:02:26.661316 -638578688 extensions.cpp:781] Required extension not found or not loaded: example_extension2
E0122 09:02:26.661329 -638578688 init.cpp:714] An error occurred during extension manager startup: Required extension not found or not loaded: example_extension2
Using a virtual database. Need help, type '.help'
osquery> W0122 09:02:29.429620 1841688576 watcher.cpp:738] Extension respawning too quickly: /Users/victor/work/fleet/example_table2.ext
W0122 09:02:29.644486 1844555776 interface.cpp:143] Could not add extension example_extension2: Duplicate registry item: example_table
2024/01/22 09:02:29 status 1 deregistering extension: No extension UUID found

Note

The osquery --extension flag can only be used to enable one and only one extension. Using that flag multiple times will cause osquery to pick up the last extension passed, and this behavior can be confused with osquery not giving an error when two tables (or extensions) with the same name are installed. This is how all osquery flags work -- they accept only one value, but there is no built-in check preventing the user from passing the same flag multiple times.

From osqueryi --help:

   --extension VALUE                                Path to a single extension to autoload

To load multiple extensions, the user can use:

    --extensions_autoload VALUE                      Optional path to a list of autoloaded & managed extensions

[sharon-fdm]

@getvictor Thanks ! If I get this right, there are some cases of infinite loop. This has to be fixed. Regarding the error msg, is it kept local or being logged so that admins can see it?

[noahtalerman]

Could not add extension example_extension2: Duplicate registry item: example_table

Hey @getvictor if I'm understanding this error message correctly, the entire extension isn't added if there is a duplicate table, is that right?

If yes, I think we should make the error message clearer: Could not add extension example_extension2: table example_table conflicts with another table with the same name.

[sharon-fdm]

@getvictor what is the frequency of printing the error msg/log? Is it every restart of osquery? Or every few seconds?

cc @noahtalerman

[getvictor]

@noahtalerman @sharon-fdm Yes, the entire extension is not added. The warning messages that try to load the extension print every 2 seconds.

FYI. I also filed an osquery issue: https://github.com/osquery/osquery/issues/8254

[sharon-fdm]

@getvictor @noahtalerman in that case (logging every 2 seconds), this has to be fixed.

[zwass]

I'm guessing that the extension exits when it gets the error from osquery and then osquery tries to restart the extension. Maybe the extension code should handle this and not register the duplicate table rather than exiting?

[getvictor]

@zwass Yes, the extension exits once it gets an error from osquery. However, the extension itself doesn't know the exact issue -- all it gets is status 1 deregistering extension: No extension UUID found. Then osquery restarts it -- osquery has a loop where it starts all its processes that are not currently running.

@sharon-fdm The infinite loop can be fixed in the extension itself by not exiting and instead waiting some time before trying to re-register itself with osquery. I think we can attribute this issue to a badly coded extension.

@noahtalerman For the error message, the message from osquery:

W0122 09:02:29.644486 1844555776 interface.cpp:143] Could not add extension example_extension2: Duplicate registry item: example_table

is a generic message that applies not only to table extensions but also to config and logging extensions. Maybe we can change it from warning to error, and change the text to be:

Could not add extension example_extension2: Registry item example_table conflicts with another item of the same name.

[noahtalerman]

is a generic message that applies not only to table extensions but also to config and logging extensions. Maybe we can change it from warning to error, and change the text to be:

Could not add extension example_extension2: Registry item example_table conflicts with another item of the same name.

@getvictor this makes sense to me. Thanks for clarifying table, config, and logging.

[fleet-release]

Two tables collide, Fleet weaves order from chaos, Clarity will guide.