vespa-engine / vespa

AI + Data, online. https://vespa.ai
https://vespa.ai
Apache License 2.0
5.69k stars 593 forks source link

After upgrading to 7.574.71 vespa-route has unexpected output #22207

Closed asdf23 closed 2 years ago

asdf23 commented 2 years ago

after preforming an upgrade: yum install vespa-7.574.71

./vespa-route --services

[2022-04-21 13:19:56.260641] 7576/5329 (.documenttyperepo) info: applying new doc type config
[2022-04-21 13:19:56.260750] 7576/5329 (.documenttyperepo) info: doc document
[2022-04-21 13:19:56.260757] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10000
[2022-04-21 13:19:56.260762] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10001
[2022-04-21 13:19:56.260767] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10009
[2022-04-21 13:19:56.260773] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10002
[2022-04-21 13:19:56.260777] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10003
[2022-04-21 13:19:56.260781] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10004
[2022-04-21 13:19:56.260785] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10005
[2022-04-21 13:19:56.260789] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10006
[2022-04-21 13:19:56.260793] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10007
[2022-04-21 13:19:56.260797] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10008
[2022-04-21 13:19:56.260801] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10010
[2022-04-21 13:19:56.260805] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10011
[2022-04-21 13:19:56.260809] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10012
[2022-04-21 13:19:56.260813] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10014
[2022-04-21 13:19:56.260817] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10013
[2022-04-21 13:19:56.260822] 7576/5329 (.documenttyperepo) info: doc hm
[2022-04-21 13:19:56.260826] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10015
[2022-04-21 13:19:56.260830] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10016
[2022-04-21 13:19:56.260835] 7576/5329 (.documenttyperepo) info: doc thesaurus
[2022-04-21 13:19:56.260840] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10017
[2022-04-21 13:19:56.260844] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10018
[2022-04-21 13:19:56.260848] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10019
[2022-04-21 13:19:56.260852] 7576/5329 (.documenttyperepo) info: doc my_businessrules
[2022-04-21 13:19:56.260856] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10020
[2022-04-21 13:19:56.260860] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10021
[2022-04-21 13:19:56.260865] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10022
[2022-04-21 13:19:56.260869] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10023
[2022-04-21 13:19:56.260873] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10024
[2022-04-21 13:19:56.260878] 7576/5329 (.documenttyperepo) info: doc my_products
[2022-04-21 13:19:56.260882] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10025
[2022-04-21 13:19:56.260887] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10026
[2022-04-21 13:19:56.260892] 7576/5329 (.documenttyperepo) info: doc my_redirect
[2022-04-21 13:19:56.260897] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10027
[2022-04-21 13:19:56.260902] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10028
[2022-04-21 13:19:56.260906] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10029
[2022-04-21 13:19:56.260910] 7576/5329 (.documenttyperepo) info: doc my_thesaurus
[2022-04-21 13:19:56.260914] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10030
[2022-04-21 13:19:56.260919] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10031
[2022-04-21 13:19:56.260923] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10032
[2022-04-21 13:19:56.260927] 7576/5329 (.documenttyperepo) info: ensure indexes: add 10033
[2022-04-21 13:19:56.260992] 7576/5329 (.documenttyperepo) info: retry complex types, 0 missing
[2022-04-21 13:19:56.283678] 7576/50318 (.slobrok.mirror) info: successfully connected to location broker tcp/myServer.myDomain.com:19099 (mirror initialized with 19 service names)
There are 7 service(s):
    1. default/container.0/chain.indexing
    2. storage/cluster.hm/distributor/0/default
    3. storage/cluster.hm/storage/0/default
    4. storage/cluster.thesaurus/distributor/0/default
    5. storage/cluster.thesaurus/storage/0/default
    6. storage/cluster.myServer/distributor/0/default
    7. storage/cluster.myServer/storage/0/default
jobergum commented 2 years ago

Thank you for your report, yes, these messages should not have been logged. This has no impact on anything else than the output of the vespa-route tool.

docker exec -it vespa bash
[root@vespa-container /]# vespa-route
[2022-04-22 08:05:11.426328] 2113/48242 (.documenttyperepo) info: applying new doc type config
[2022-04-22 08:05:11.426517] 2113/48242 (.documenttyperepo) info: doc document
[2022-04-22 08:05:11.426543] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10000
[2022-04-22 08:05:11.426590] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10001
[2022-04-22 08:05:11.426635] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10009
[2022-04-22 08:05:11.426662] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10002
[2022-04-22 08:05:11.426710] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10003
[2022-04-22 08:05:11.426732] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10004
[2022-04-22 08:05:11.426753] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10005
[2022-04-22 08:05:11.426801] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10006
[2022-04-22 08:05:11.426820] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10007
[2022-04-22 08:05:11.426837] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10008
[2022-04-22 08:05:11.426855] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10010
[2022-04-22 08:05:11.426916] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10011
[2022-04-22 08:05:11.427029] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10012
[2022-04-22 08:05:11.427051] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10014
[2022-04-22 08:05:11.427074] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10013
[2022-04-22 08:05:11.427093] 2113/48242 (.documenttyperepo) info: doc track
[2022-04-22 08:05:11.427112] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10015
[2022-04-22 08:05:11.427126] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10016
[2022-04-22 08:05:11.427146] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10018
[2022-04-22 08:05:11.427168] 2113/48242 (.documenttyperepo) info: ensure indexes: add 10017
[2022-04-22 08:05:11.427323] 2113/48242 (.documenttyperepo) info: retry complex types, 0 missing
[2022-04-22 08:05:11.527203] 2113/27696 (.slobrok.mirror) info: successfully connected to location broker tcp/vespa-container:19099 (mirror initialized with 9 service names)
There are 6 route(s):
    1. default
    2. default-get
    3. storage/cluster.tracks
    4. tracks
    5. tracks-direct
    6. tracks-index

There are 2 hop(s):
    1. default/chain.indexing
    2. indexing
baldersheim commented 2 years ago

@arnej27959 should the slobrok.mirror message be silenced too ?

arnej27959 commented 2 years ago

@arnej27959 should the slobrok.mirror message be silenced too ?

yes and no :-( we have had problems some months ago and added the mirror logging to see if we could understand what was going on. so we want to keep it as-is for that. but we want to make it debug level at some point.

baldersheim commented 2 years ago

OK, Present in 7.577.4 and on