之所以会写这篇文章,是因为之前nova那边遇到了一点小问题,现象如下:
从日志来看,很简单嘛,定时器超时了。但是为什么会超时呢?纯粹的增加一下超时时间行不行?要想解决这个问题,就不得不说一下OVS的数据库交互机制。
OVSDB不是类似MYSQL一样的数据库,而是一个以JSON格式书写的文件数据库。简单点说吧,就是这个数据库里写的都是一些执行命令,每次有什么更新或者系统初始化时,都会逐条地去执行数据库里的指令。看看下面的例子:
但其实这里并不太会导致增删端口超时。之前做过一个测试,4k的namespace,每个namespace 4个端口,也就是总共16K的端口,如果直接从文件里读出后写入内核,大概总共只需要10多分钟。
而如果是通过ovs-vsctl的命令去执行,当加完8k个端口之后,每加一个端口,大概需要30多分钟的时间。这是很可怕的一个数字。
问题已经抛出来了,接下来看看造成这个问题的根源。这里我并不想解说OVSDB每一个数据表以及列的格式,JSON消息格式,这些在RFC7047上都写得很清楚。下面通过一张图来说明OVSDB与其他进程的交互过程。
每一次进程启动的时候,都会把自己感兴趣的内容通知OVSDB,就是图中看到的monitor request,俗称消息订阅。
数据库在收到订阅消息后,会把数据库里存储的符合条件的记录发给相应的客户端,然后客户端把记录存储下来,执行相应的动作,到这里为止初始化结束。
接下来,用户想通过VSCTL来加删端口,此时客户端向服务端发送transaction信息,内容一般包括:
要满足哪些前提条件(用op wait表示);
要增加哪些内容(用op insert表示);
要删除哪些内容(用op delete表示);
要更新哪些内容(用op mutate表示)。
服务端收到交易信息后,会把这些内容记录到数据库里,同时查看所有和服务器存在连接的客户端,如果该客户端对VSCTL发过来的消息感兴趣(就是之前的订阅过的消息),就发送update更新消息给它的客户端。到这里为止,加删端口的过程基本结束,就是图中绿线标注的那几个流程。最后的4和6这两个流程,用途一般有两个:
一个是vswitchd将自己的状态和端口统计值发给服务器;
另一个就是通知VSCTL,我vswithcd这边加删端口已经处理完毕,你现在可以安全的返回了。
谈了这么多,貌似还没有讲到重点。对啊,这个交互流程有啥问题呢?别急,马上就来揭开神秘的面纱。
VSCTL有两个跟超时相关的参数,
一个是timeout,这个在文章的开头已经看到了,一旦这个时间expired,vsctl进程会立即退出,此时有可能是OVSDB那边还在处理,也有可能是vswitchd那边处理还没完成。不管哪种情况,如果这个前提下还做相关的操作(比如给tap端口set link up),那么必然报错。
一个是no-wait,这个参数默认为false(也就是不指定),该参数主要用于等待vswitchd那边的执行结果返回。那么我们怎么看vswitchd那边执行完成了呢?
也很简单,看命令ovs-vsctl list Open_vSwitch:
如果cur_cfg的值小于next_cfg,说明vswitchd还没执行结束;反之,若cur_cfg>=next_cfg,则vswitchd已经完成任务。
接下来通过一个加端口的过程来具体谈一下超时的瓶颈在哪里。先说一个小工具,个人感觉还蛮有用。
我们怎么来看每个进程执行每条命令花的时间有多长呢?很简单,看日志。但是,openvswitch默认的日志级别是INFO,也就是说只有CRITICAL,ERROR,WARN和INFO这类level的日志才会被记录到文件里,普通的如JSON消息的收发是不记录的。
如果我们在进程启动时没有刻意去设置过类似这样的-vsyslog:err -vfile:info,那么有没有办法在进程运行过程中动态修改日志级别呢?这就需要使用命令
ovs-appctl --target=/usr/local/var/run/openvswitch/ovs-vswitchd.29384.ctl vlog/set ANY:ANY:info
ovs-vswitchd.29384.ctl这个是进程pid,ANY:ANY:info分别代表
vlog module(包括vsctl(VLM_vsctl), vswitchd(VLM_vswitchd),ovsdb_server(VLM_ovsdb_server));
vlog facility(console(VLF_CONSOLE), syslog(VLF_SYSLOG),file(VLF_FILE))
vlog level(off(VLL_OFF 1),emer(VLL_EMER 1),err(VLL_ERR 3),warn(VLL_WARN 4),info(VLL_INFO 5),dbg(VLL_DBG 7))。
具体的可以查阅相关文档,不再赘述。如果只想看vsctl的具体信息,只要使用的时候加个-v参数即可。
言归正传。看看加端口的时候VSCTL都做了哪些事情。
步骤一:发送订阅消息
method="monitor",
params=[
"Open_vSwitch",
null,
{"Port":{"columns":["fake_bridge","interfaces","name","tag"]},
"Interface":{"columns":["mac","name","ofport_request","type"]},
"Bridge":{"columns":["controller","fail_mode","name","ports"]},
"Controller":{"columns":[]},
"Open_vSwitch":{"columns":["bridges","cur_cfg"]}}
], id=0
cur_cfg只会在no-wait选项为false的时候会订阅。从这里可以看到,增加一个端口的时候,关心所有的bridge,port和interface。
步骤二:得到数据库里的初始值
result={
"Port":{"275537c3-b469-47d1-b3c0-10efd08cb193": {"new":{"name":"br0","fake_bridge":false,"interfaces":["uuid","34663327-aeca-417d-a91b-8c8f796cb873"],"tag":["set",[]]}}},
"Interface":{"34663327-aeca-417d-a91b-8c8f796cb873":{"new":{"ofport_request":["set",[]],"name":"br0","mac":["set",[]],"type":"internal"}}},
"Bridge":{"8f725ab8-c5f4-4077-a251-d866e7a448d9": {"new":{"fail_mode":["set",[]],"name":"br0","ports":["uuid","275537c3-b469-47d1-b3c0-10efd08cb193"],"controller":["set",[]]}}},
"Open_vSwitch":{"49c7f033-83c3-4bdf-8c0d-3d13b0c8bcf7":{"new":{"bridges":["uuid","8f725ab8-c5f4-4077-a251-d866e7a448d9"],"cur_cfg":1008}}}
}, id=0
Port和interface的返回值都是一个字典,也就是说,当前有多少端口就会返回多少数据。Key是port uuid和interface uuid,value就是刚刚订阅的那些列的内容。
Bridge也是一个字典,但是它的内容庞大主要在于bridge的ports这一列所含的数据是所有属于该bridge的port uuid。
步骤三:发送add port transaction消息
method="transact",
params=[
"Open_vSwitch",
{"rows":[{"ports":["uuid","275537c3-b469-47d1-b3c0-10efd08cb193"]}],
"columns":["ports"],
"table":"Bridge",
"until":"==",
"where":[["_uuid","==",["uuid","8f725ab8-c5f4-4077-a251-d866e7a448d9"]]],
"timeout":0,
"op":"wait"},
{"rows":[{"interfaces":["uuid","34663327-aeca-417d-a91b-8c8f796cb873"]}],
"columns":["interfaces"],
"table":"Port",
"until":"==",
"where":[["_uuid","==",["uuid","275537c3-b469-47d1-b3c0-10efd08cb193"]]],
"timeout":0,
"op":"wait"},
{"rows":[{"bridges":["uuid","8f725ab8-c5f4-4077-a251-d866e7a448d9"]}],
"columns":["bridges"],
"table":"Open_vSwitch",
"until":"==",
"where":[["_uuid","==",["uuid","49c7f033-83c3-4bdf-8c0d-3d13b0c8bcf7"]]],
"timeout":0,
"op":"wait"},
{"row":{"ofport_request":100,"name":"p100","mac":"00:00:00:01:01:01","type":"internal"},
"table":"Interface",
"uuid-name":"row84ca2c84_4665_4889_9fda_14cef22ae33e",
"op":"insert"},
{"row":{"ports":["set",[["uuid","275537c3-b469-47d1-b3c0-10efd08cb193"],["named-uuid","rowe8af9c67_3aa9_4b01_be99_d3cc7aeb8b78"]]]},
"table":"Bridge",
"where":[["_uuid","==",["uuid","8f725ab8-c5f4-4077-a251-d866e7a448d9"]]],
"op":"update"},
{"row":{"name":"p100","interfaces":["named-uuid","row84ca2c84_4665_4889_9fda_14cef22ae33e"],"tag":100},
"table":"Port",
"uuid-name":"rowe8af9c67_3aa9_4b01_be99_d3cc7aeb8b78",
"op":"insert"},
{"mutations":[["next_cfg","+=",1]], //next_cfg只会在--no-wait选项没有的时候发送
"table":"Open_vSwitch",
"where":[["_uuid","==",["uuid","49c7f033-83c3-4bdf-8c0d-3d13b0c8bcf7"]]],
"op":"mutate"},
{"columns":["next_cfg"], //next_cfg只会在--no-wait选项没有的时候发送
"table":"Open_vSwitch",
"where":[["_uuid","==",["uuid","49c7f033-83c3-4bdf-8c0d-3d13b0c8bcf7"]]],
"op":"select"},
{"comment":"ovs-vsctl: ./ovs-vsctl -v add-port br0 p100 -- set Interface p100 ofport_request=100 type=internal \"mac=\\"00:00:00:01:01:01\\"\" -- set Port p100 tag=100", "op":"comment"}], id=1
从这里可以看到,所有的port,interface, bridge都被作为前提条件发过去了。
步骤四:接收OVSDB发过来的update消息
method="update",
params=[null,
{"Port":{"4ba835b7-2ed0-4526-b948-dba1674df899":{"new":{"name":"p100","fake_bridge":false,"interfaces":["uuid","b54ccab2-e910-4b90-a13f-de513b7a139f"],"tag":100}} },
"Bridge":{"8f725ab8-c5f4-4077-a251-d866e7a448d9":{"old":{"ports":["uuid","275537c3-b469-47d1-b3c0-10efd08cb193"]},"new":{"fail_mode":["set",[]],"name":"br0","ports":["set",[["uuid","275537c3-b469-47d1-b3c0-10efd08cb193"],["uuid","4ba835b7-2ed0-4526-b948-dba1674df899"]]],"controller":["set",[]]}} },
"Interface":{"b54ccab2-e910-4b90-a13f-de513b7a139f":{"new":{"ofport_request":100,"name":"p100","mac":"00:00:00:01:01:01","type":"internal"}}}}]
只有之前monitor过的表和列才会发送信息
步骤五:接收执行结果
result=[
{},
{},
{},
{"uuid":["uuid","b54ccab2-e910-4b90-a13f-de513b7a139f"]},
{"count":1},
{"uuid":["uuid","4ba835b7-2ed0-4526-b948-dba1674df899"]},
{"count":1},
{"rows":[{"next_cfg":1009}]},
{}], id=1
看到此处的next_cfg了吗?一旦OVSDB执行完毕,next_cfg就已经比上次的值要增加了,但是cur_cfg值还没有变化。
步骤六:接收vswitchd执行完毕的update消息
method="update",
params=[null,
{"Open_vSwitch":{"49c7f033-83c3-4bdf-8c0d-3d13b0c8bcf7":{"old":{"cur_cfg":1008},"new":{"bridges":["uuid","8f725ab8-c5f4-4077-a251-d866e7a448d9"],"cur_cfg":1009}}}}]
此时终于把cur_cfg更新成和next_cfg值一样了,VSCTL可以高高兴兴的退出了。
看了这个流程,估计很多人还是没反应过来,这怎么就反应慢了呢?确实,光看这么一个port不会有任何的效果,如果再执行一次加port的命令, 或者在已经加完100个端口后,再用命令ovs-vsctl –v add-port命令,此时就看得很明白了。 在步骤二,三,四中可以看到黑压压的一片,都是我们的JSON消息里填的portid,interface id等信息。 我们知道,报文每一次加封装和解封装都是需要时间的,内容越多,耗时越长。这个有兴趣的人可以自己打开debug去看日志时间。
也就是说,加端口的时候大部分的时间都花在报文的加解封装上了,端口数越多,时间越长。那么,怎么解决呢?奉上之前的劳动成果:
a. 使bridge表不再包含ports列,而改为port表里增加bridge的列引用。这样一来,bridge表返回的内容就大大减少
b. 监视内容,不再是所有的port,interface和bridge。而是和命令相关的数据。比如,要删一个port tapxxx, 那么就只查询和该port tapxxx相关的数据,其他的数据一概不处理。这样的话,步骤二和步骤三里的数据就大大减少。 也就是说,监视的消息格式里要加上condition选项,只有符合条件的才返回。
这里有一份数据,仅供参考。试数据是4000个端口,1000个namespace,每个namespace共4个端口
网易云新用户大礼包:https://www.163yun.com/gift
本文来自网易实践者社区,经作者陈跃芳授权发布。