最近,我们团队在生产环境中遇到了一个问题,就是casdoor服务重启后,日志也显示出来了,但是就是无法访问,使用curl在本地访问也是不通。

日志:

log

首先先简绍一下casdoor是什么概述 | Casdoor · An open-source UI-first Identity and Access Management (IAM) / Single-Sign-On (SSO) platform with web UI supporting OAuth 2.0, OIDC, SAML, CAS, LDAP, SCIM, WebAuthn, TOTP, MFA, RADIUS, Google Workspace, Active Directory and Kerberos

简单点理解就是它是一个实现了OAuth 2.0认证的一个服务,我们可以利用它来完成一个账号对多个应用进行无感登录,同时可以把用户数据放到casdoor中,其它应用的数据库可以只用来存放业务数据。

环境

根据相关同学的描述,生产环境的casdoor环境如下。

  • 3台服务器使用dockerpodman启动了一个casdoor服务,实现高可用
  • 3台服务器同时使用同一个数据库(mysql)
  • 使用nfs来同步casdoor中的tmp文件,该文件为casdoor的默认session保存位置
    • session配置的相关文档
    • 当时该 tmp 文件大小至少有40G,但是我们环境当前的用户数量不至于会有这么多的session缓存
    • nfs对应挂载服务的进程占用过高的cpu
  • casdoor的版本为1.814,其中的beego版本为1.12.3

排查

后续的排查环境是在测试环境中搭建的,并且复刻了对应的问题。环境如下

  • 使用dcoker-compose启动了3个casdoor和一个mysql
  • 宿主机的8001,8002,8003分别映射3个casdoor的8000端口
  • 使用了 docker 的挂载把tmp文件同时挂载到了每个casdoor的目录(模拟nfs
  • tmp的文件大小为31G

端口转发

因为服务是使用docker启动的,并且使用的网络模式为Bridge,所以我们先排查docker网络相关的问题。

curl docker的网卡(docker0)的ip地址,但是还是 curl 不通相关服务。

[root@rocky-testing casdoor]# ss -anpl | grep 8001 # 查看端口监听情况
tcp   LISTEN 0      4096  0.0.0.0:8001             0.0.0.0:*    users:(("docker-proxy",pid=1456272,fd=7)) 
tcp   LISTEN 0      4096 [::]:8001                [::]:*    users:(("docker-proxy",pid=1456280,fd=7))     
[root@rocky-testing casdoor]# ifconfig docker0 #获取docker的网卡
docker0: flags=4099<UP,BROADCAST,MULTICAST>  mtu 1500
        inet 172.17.0.1  netmask 255.255.0.0  broadcast 172.17.255.255
        inet6 fe80::1469:daff:febf:1315  prefixlen 64  scopeid 0x20<link>
        ether 16:69:da:bf:13:15  txqueuelen 0  (Ethernet)
        RX packets 32519  bytes 2160933 (2.0 MiB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 37734  bytes 94754551 (90.3 MiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

[root@rocky-testing casdoor]# curl 172.17.0.1:8001 # curl 对应的网卡ip 8001为casdoor启动的端口

使用nsenter 进入对应服务的network ns,并尝试curl访问服务,但还是无法访问

[root@rocky-testing casdoor]# docker compose top casdoor-1 # 获取应用的pid
WARN[0000] /root/test/casdoor/docker-compose.yaml: the attribute `version` is obsolete, it will be ignored, please remove it to avoid potential confusion 
casdoor-1
UID    PID       PPID      C    STIME   TTY   TIME       CMD
1000   1456231   1456210   4    14:58   ?     00:01:21   /server   
[root@rocky-testing casdoor]# nsenter -n --target 1456231 # 进入对应的 ns
[root@rocky-testing casdoor]# ip link # 查看网卡,跟宿主机的网卡不一致,只剩下lo和eth0网卡,说明进入了容器的ns中
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN mode DEFAULT group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2: eth0@if898: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP mode DEFAULT group default 
    link/ether 82:2e:b0:c9:cc:00 brd ff:ff:ff:ff:ff:ff link-netnsid 0
[root@rocky-testing casdoor]# ss -anlp | grep 8000 # 查看端口占用,确实服务已经启动 
tcp   LISTEN 0      4096               *:8000               *:*    users:(("server",pid=1456231,fd=13))
[root@rocky-testing casdoor]# curl 0.0.0.0:8000 # 无法curl通服务
[root@rocky-testing casdoor]# exit # 退出对应ns
logout

strace\pstack查看系统调用

在上述的两步操作后,还是curl不通,说明服务虽然日志已经打印了,但是服务还未可用。

使用stracepstack命令查看对应应用的系统调用,查看casdoor的启动后的行为

strace -p 1456231 -f -o ./strace-casdoor-1.log 
pstack 1456231 > ./pstack-casdoor-1.log

查看其日志,以下日志内容为生产环境中获取的stracepstack日志

# 分析strace的日志,发现程序是有规律的执行以下系统调用
... 都是nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0 的调用
1146720 nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
1146720 futex(0x45252c0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=103439635} <unfinished ...>
1146729 <... newfstatat resumed>{st_mode=S_IFREG|0644, st_size=20, ...}, AT_SYMLINK_NOFOLLOW) = 0
1146729 --- SIGURG {si_signo=SIGURG, si_code=SI_TKILL, si_pid=1, si_uid=1000} ---
1146729 rt_sigreturn({mask=[]})         = 0
1146729 futex(0x45252c0, FUTEX_WAKE_PRIVATE, 1) = 1
1146720 <... futex resumed>)            = 0
1146729 newfstatat(AT_FDCWD, "tmp/0/0/001575f66990e62d6ed701f24599e1ca",  <unfinished ...>
1146720 nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
1146720 futex(0x45252c0, FUTEX_WAIT_PRIVATE, 0, {tv_sec=0, tv_nsec=43396353} <unfinished ...>
1146704 <... epoll_pwait resumed>[], 128, 998, NULL, 0) = 0
1146704 epoll_pwait(4, [], 128, 0, NULL, 0) = 0
1146704 epoll_pwait(4,  <unfinished ...>
1146720 <... futex resumed>)            = -1 ETIMEDOUT (Connection timed out)
1146720 nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0
... 都是nanosleep({tv_sec=0, tv_nsec=20000}, NULL) = 0 的调用
# 分析pstack日志,程序也是不停地执行以下方法
 37028.625 (47.259 ms): server/1146720  ... [continued]: futex())                                            = 0
 37075.871 (         ): server/1146729 newfstatat(dfd: CWD, filename: 0xb77bf0, statbuf: 0xc000adced8, flag: SYMLINK_NOFOLLOW) ...
 37075.900 ( 0.058 ms): server/1146720 nanosleep(rqtp: 0xc00008ff10)                                         = 0
 37075.871 (62.859 ms): server/1146729  ... [continued]: newfstatat())                                       = 0
 37075.965 (         ): server/1146720 futex(uaddr: 0x45252c0, op: WAIT|PRIVATE_FLAG, utime: 0xc00008feb0) ...
 37138.754 ( 0.012 ms): server/1146729 futex(uaddr: 0x45252c0, op: WAKE|PRIVATE_FLAG, val: 1)                = 1
 37075.965 (62.898 ms): server/1146720  ... [continued]: futex())                                            = 0
 37138.781 (         ): server/1146729 newfstatat(dfd: CWD, filename: 0xb77c50, statbuf: 0xc000adcfa8, flag: SYMLINK_NOFOLLOW) ...
 37138.881 ( 0.067 ms): server/1146720 nanosleep(rqtp: 0xc00008ff10)                                         = 0
 37138.954 (25.650 ms): server/1146720 futex(uaddr: 0x45252c0, op: WAIT|PRIVATE_FLAG, utime: 0xc00008feb0)   = -1 ETIMEDOUT (Connection timed out)
 37164.628 ( 0.088 ms): server/1146720 nanosleep(rqtp: 0xc00008ff10)                                         = 0
 37164.724 ( 0.110 ms): server/1146720 nanosleep(rqtp: 0xc00008ff10)                                         = 0
 37164.845 ( 0.085 ms): server/1146720 nanosleep(rqtp: 0xc00008ff10)                                         = 0

通过上述的分析,可以发现casdoor程序在启动后,一直读取tmp目录下的文件信息(并且其中还有一个锁),结合前面的信息可以得出casdoor在启动的时候会一直读取tmp里面的session信息,导致nfs的进程的cpu使用率过高。

所以后面在生产环境中把nfs的挂载给取消了(tmp中的session文件就会被清空,变成一个空文件夹),后面再启动,就可以正常访问服务了,后续可能会考虑把session放到redis中进行处理。

问题🤔

虽然服务可以启动了但是留下了3个问题:

  • 为什么casdoor启动的时候要去访问session文件(tmp目录下的文件)
  • 为什么casdoor的日志都显示服务的端口已经监听了,为什么curl该服务还是不能马上返回请求
  • 同学反映该tmp文件之前已经清理过一次了,但是一天左右磁盘占用率又上来了这是为什么

针对上面的3个问题,我选择 源码 启动👀

问题1

为什么casdoor启动要去访问session文件

首先找到对应的github.dev/casdoor/casdoor/tree/v1.814.0版本,查看其main.go

https://github.dev/casdoor/casdoor/blob/a5a627f92efd3cc3f3613ca119b340b66258ce64/main.go#L65-L95
	....
	beego.BConfig.WebConfig.Session.SessionOn = true
	beego.BConfig.WebConfig.Session.SessionName = "casdoor_session_id"
	if conf.GetConfigString("redisEndpoint") == "" {
		beego.BConfig.WebConfig.Session.SessionProvider = "file"
		beego.BConfig.WebConfig.Session.SessionProviderConfig = "./tmp"
	} else {
		beego.BConfig.WebConfig.Session.SessionProvider = "redis"
		beego.BConfig.WebConfig.Session.SessionProviderConfig = conf.GetConfigString("redisEndpoint")
	}
	beego.BConfig.WebConfig.Session.SessionCookieLifeTime = 3600 * 24 * 30 //30天的缓存时间
	beego.BConfig.WebConfig.Session.SessionGCMaxLifetime = 3600 * 24 * 30 //30天的缓存时间
	// beego.BConfig.WebConfig.Session.SessionCookieSameSite = http.SameSiteNoneMode

	err := logs.SetLogger(logs.AdapterFile, conf.GetConfigString("logConfig"))
	if err != nil {
		panic(err)
	}
	port := beego.AppConfig.DefaultInt("httpport", 8000)
	// logs.SetLevel(logs.LevelInformational)
	logs.SetLogFuncCall(false)

	err = util.StopOldInstance(port)
	if err != nil {
		panic(err)
	}

	go ldap.StartLdapServer()
	go radius.StartRadiusServer()
	go object.ClearThroughputPerSecond()

	beego.Run(fmt.Sprintf(":%v", port))

在上面的代码里面,我们可以看到默认情况下casdoor使用了SessionProviderfile,并且目录配置到了./tmp下面,后面启动的就是beego的服务了,所以后面查看的是对应版本beego的源码。

首先从beego.go开始启动服务

https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/beego.go#L51-L73
// Run beego application.
// beego.Run() default run on HttpPort
// beego.Run("localhost")
// beego.Run(":8089")
// beego.Run("127.0.0.1:8089")
func Run(params ...string) {
	initBeforeHTTPRun() //这里再程序启动前,调用了initBeforeHTTPRun这个方法
	if len(params) > 0 && params[0] != "" {
		strs := strings.Split(params[0], ":")
		if len(strs) > 0 && strs[0] != "" {
			BConfig.Listen.HTTPAddr = strs[0]
		}
		if len(strs) > 1 && strs[1] != "" {
			BConfig.Listen.HTTPPort, _ = strconv.Atoi(strs[1])
		}

		BConfig.Listen.Domains = params
	}

	BeeApp.Run()
}
....
https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/beego.go#L91-L107
func initBeforeHTTPRun() {
	//init hooks 在这个方法中注册了Session服务
	AddAPPStartHook(
		registerMime,
		registerDefaultErrorHandler,
		registerSession,
		registerTemplate,
		registerAdmin,
		registerGzip,
	)

	for _, hk := range hooks {
		if err := hk(); err != nil { //在这里执行了注册的session服务
			panic(err)
		}
	}
}

查看对应的registerSession的代码实现,在hook.go

https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/hooks.go#L47-L76
func registerSession() error {
	if BConfig.WebConfig.Session.SessionOn {
		var err error
		sessionConfig := AppConfig.String("sessionConfig")
		conf := new(session.ManagerConfig)
		if sessionConfig == "" {
			....
            conf.Gclifetime = BConfig.WebConfig.Session.SessionGCMaxLifetime //定义了session的存活时间
			conf.ProviderConfig = filepath.ToSlash(BConfig.WebConfig.Session.SessionProviderConfig) //在这里tmp的配置变成了文件路径配置
			....
		} else {
			if err = json.Unmarshal([]byte(sessionConfig), conf); err != nil {
				return err
			}
		}
		if GlobalSessions, err = session.NewManager(BConfig.WebConfig.Session.SessionProvider, conf); err != nil {
			return err
		}
		go GlobalSessions.GC() //这里使用了GO协程启动了一个CG服务,该操作不会阻塞主协程
	}
	return nil
}

进入GlobalSessions.GC() 函数查看对应实现,在session.go

https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/session/session.go#L290-L295
// GC Start session gc process.
// it can do gc in times after gc lifetime.
func (manager *Manager) GC() {
	manager.provider.SessionGC() //启动时先执行一次SessionCG 然后再使用time.AfterFunc来定时执行
	time.AfterFunc(time.Duration(manager.config.Gclifetime)*time.Second, func() { manager.GC() })
}

进入manager.provider.SessionGC() 函数查看其实现,因为我们使用的sessionProviderfile,所以要在session/sess_file.go中查看其实现

// filepder的定义
https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/session/sess_file.go#L30-L33
var (
	filepder      = &FileProvider{}
	gcmaxlifetime int64
)
https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/session/sess_file.go#L113-L118
// FileProvider File session provider
type FileProvider struct {
	lock        sync.RWMutex
	maxlifetime int64
	savePath    string
}
https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/session/sess_file.go#L200-L207
// SessionGC Recycle files in save path
func (fp *FileProvider) SessionGC() {
	filepder.lock.Lock() //这里先锁住了filepder 这个锁很关键
	defer filepder.lock.Unlock()

	gcmaxlifetime = fp.maxlifetime //获取gc超时时间
	filepath.Walk(fp.savePath, gcpath) //这里使用walk来浏览session文件目录下的文件,并且执行gcpath的回调
}
....
https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/session/sess_file.go#L284-L296
// remove file in save path if expired
func gcpath(path string, info os.FileInfo, err error) error {
	if err != nil {
		return err
	}
	if info.IsDir() {
		return nil
	}
	if (info.ModTime().Unix() + gcmaxlifetime) < time.Now().Unix() {
		os.Remove(path) //如果该文件的修改时间加上超时时间大于当前时间则进行删除
	}
	return nil
}

到此第一个问题已经解决了,就是因为beego.go启动的时候会执行session的GC,而程序配置为利用file保存session,所以就解释了为什么查看stracepstack的日志时会有锁futex 和文件读取的newfstatat的系统调用

问题2

为什么日志已经显示了端口绑定了,但是curl对应服务还是不通

在上面我们得知我们的服务是在beego.go中启动的,所以先查看其源码

https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/beego.go#L51-L73
// Run beego application.
// beego.Run() default run on HttpPort
// beego.Run("localhost")
// beego.Run(":8089")
// beego.Run("127.0.0.1:8089")
func Run(params ...string) {
	initBeforeHTTPRun() //这里再程序启动前,调用了initBeforeHTTPRun这个方法
	if len(params) > 0 && params[0] != "" {
		strs := strings.Split(params[0], ":")
		if len(strs) > 0 && strs[0] != "" {
			BConfig.Listen.HTTPAddr = strs[0]
		}
		if len(strs) > 1 && strs[1] != "" {
			BConfig.Listen.HTTPPort, _ = strconv.Atoi(strs[1])
		}

		BConfig.Listen.Domains = params
	}

	BeeApp.Run() //正式启动服务
}

我们这里直接查看BeeApp.Run()的实现

https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/app.go#L62-L239
// Run beego application.
func (app *App) Run(mws ...MiddleWare) {
	addr := BConfig.Listen.HTTPAddr

	if BConfig.Listen.HTTPPort != 0 {
		addr = fmt.Sprintf("%s:%d", BConfig.Listen.HTTPAddr, BConfig.Listen.HTTPPort)
	}
	app.Server.Handler = app.Handlers //这里的app.Handlers就是定义好的路由和服务,把它注册到http服务的回调里面
	// run cgi server
	if BConfig.Listen.EnableFcgi {
		....
	}
	....
	// run graceful mode
	if BConfig.Listen.Graceful {
        ...
	}
	// run normal mode
	if BConfig.Listen.EnableHTTPS || BConfig.Listen.EnableMutualHTTPS {
		...
	}
	if BConfig.Listen.EnableHTTP {
		go func() {
			app.Server.Addr = addr
			logs.Info("http server Running on http://%s", app.Server.Addr) //对应的casdoor日志打印的地方
			if BConfig.Listen.ListenTCP4 {
                ...
			} else {
				if err := app.Server.ListenAndServe(); err != nil { //服务启动了
					logs.Critical("ListenAndServe: ", err)
					time.Sleep(100 * time.Microsecond)
					endRunning <- true
				}
			}
		}()
	}
	<-endRunning
}

那么当有请求过来的时候,就会调用app.Handlers中的ServeHTTP来处理(必须实现HandlerFunc ),app.Handlers就在route.go里面

https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/router.go#L693-L975
// Implement http.Handler interface.
func (p *ControllerRegister) ServeHTTP(rw http.ResponseWriter, r *http.Request) {
	startTime := time.Now()
	....
    https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/router.go#L756-L770
	// session init 在这里将会处理请求中的session
	if BConfig.WebConfig.Session.SessionOn {
		var err error
		context.Input.CruSession, err = GlobalSessions.SessionStart(rw, r) //通过rw和r获取对应的session信息
		if err != nil {
			logs.Error(err)
			exception("503", context)
			goto Admin
		}
		defer func() {
			if context.Input.CruSession != nil {
				context.Input.CruSession.SessionRelease(rw)
			}
		}()
	}
	...
}

GlobalSessions.SessionStart其实现的方法在session/session.go

https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/session/session.go#L207-L253
// SessionStart generate or read the session id from http request.
// if session id exists, return SessionStore with this id.
func (manager *Manager) SessionStart(w http.ResponseWriter, r *http.Request) (session Store, err error) {
    sid, errs := manager.getSid(r) // 在请求中获取sid (sessionId)
	if errs != nil {
		return nil, errs
	}

	if sid != "" && manager.provider.SessionExist(sid) { // 如果获取到就用id来查看对应的sessionStore,可以通过sessionStore来管理sessoin
		return manager.provider.SessionRead(sid)
	}

	// Generate a new session 如果获取不到session就重新生成session
	sid, errs = manager.sessionID()
	if errs != nil {
		return nil, errs
	}

	session, err = manager.provider.SessionRead(sid)
	if err != nil {
		return nil, err
	}
    // 设置一个cookie,把sid放到cookie中,下次即可在请求中获取对应的sid,从而获取session
	cookie := &http.Cookie{
		Name:     manager.config.CookieName,
		Value:    url.QueryEscape(sid),
		Path:     "/",
		HttpOnly: !manager.config.DisableHTTPOnly,
		Secure:   manager.isSecure(r),
		Domain:   manager.config.Domain,
		SameSite: manager.config.CookieSameSite,
	}
	if manager.config.CookieLifeTime > 0 {
		cookie.MaxAge = manager.config.CookieLifeTime
		cookie.Expires = time.Now().Add(time.Duration(manager.config.CookieLifeTime) * time.Second)
	}
	if manager.config.EnableSetCookie {
		http.SetCookie(w, cookie)
	}
	r.AddCookie(cookie)

	if manager.config.EnableSidInHTTPHeader {
		r.Header.Set(manager.config.SessionNameInHTTPHeader, sid)
		w.Header().Set(manager.config.SessionNameInHTTPHeader, sid)
	}

	return
}

在上述的源码中,我们应该要关注里面的SessionExistSessionRead 的实现,所以我们查看对应的源码,在session/sess_file.go

https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/session/sess_file.go#L176-L190
// SessionExist Check file session exist.
// it checks the file named from sid exist or not.
func (fp *FileProvider) SessionExist(sid string) bool {
	filepder.lock.Lock() // 这里跟上面的sessionCG一样,上锁了
	defer filepder.lock.Unlock()

	if len(sid) < 2 {
		SLogger.Println("min length of session id is 2", sid)
		return false
	}

	_, err := os.Stat(path.Join(fp.savePath, string(sid[0]), string(sid[1]), sid))
	return err == nil
}

https://github.com/beego/beego/blob/c280209bf5b94cf31094a200b166c97eb3898851/session/sess_file.go#L128-L176
// SessionRead Read file session by sid.
// if file is not exist, create it.
// the file path is generated from sid string.
func (fp *FileProvider) SessionRead(sid string) (Store, error) {
	invalidChars := "./"
	...
	filepder.lock.Lock() // 这里跟上面的sessionCG一样,上锁了
	defer filepder.lock.Unlock()

	err := os.MkdirAll(path.Join(fp.savePath, string(sid[0]), string(sid[1])), 0755) //创建对应的文件夹
	if err != nil {
		SLogger.Println(err.Error())
	}
    // 获取文件并写入session信息或者创建对应的文件并写入session信息
	_, err = os.Stat(path.Join(fp.savePath, string(sid[0]), string(sid[1]), sid)) 
	var f *os.File
	if err == nil {
		f, err = os.OpenFile(path.Join(fp.savePath, string(sid[0]), string(sid[1]), sid), os.O_RDWR, 0777)
	} else if os.IsNotExist(err) {
		f, err = os.Create(path.Join(fp.savePath, string(sid[0]), string(sid[1]), sid))
	} else {
		return nil, err
	}

	defer f.Close()
	// 修改文件Modify时间,在CG中也是通过该属性判断文件是否要被CG
	os.Chtimes(path.Join(fp.savePath, string(sid[0]), string(sid[1]), sid), time.Now(), time.Now())
	var kv map[interface{}]interface{}
    // 读取session信息
	b, err := ioutil.ReadAll(f)
	if err != nil {
		return nil, err
	}
	if len(b) == 0 {
		kv = make(map[interface{}]interface{})
	} else {
		kv, err = DecodeGob(b)
		if err != nil {
			return nil, err
		}
	}

	ss := &FileSessionStore{sid: sid, values: kv}
	return ss, nil
}

所以我们这里就可以解释,为什么日志显示服务启动了,但是请求就是不行

因为在一开始启动的时候,beego就会自己对session文件进行CG同时lock了一个RWMutex

后面请求过来的时候,beego又会读取为了读session而上锁,但是如果前面的CG还未执行完成,那么这个就会被阻塞,直到可以上锁为止

所以当tmpsession文件过多,那么启动的时候就要花大量时间进行CG导致请求被卡住,也说明为什么在生产环境中nfs的挂载进程会cpu过高,然后把nfs取消挂载后(tmp中的session被清空后),启动后马上就可以正常访问了

以下是在测试环境的模拟

[root@rocky-testing casdoor]# du -h --max-depth=1 ./shared-tmp/ 
....
31G     ./shared-tmp/ # 这里弄了一个31G的session请求

重启一个casdoor服务后,curl该服务

log

在第一个curl通了以后,后面的curl服务响应时间才会正常

log

问题3

为什么一天多的时间,tmp文件会产生很多的文件,占用比较大的存储?

这就不得不提这个casdoor了,从上面我们知道casdoor可以让是用来解决用户在多个应用中的登录问题的,那么应用在用户登录的时候就要访问casdoor获取用户的信息,而刚好,我们在生产的环境中,有一个服务大概会每秒请求casdoor服务3次左右(后面改成利用缓存机制了),同时casdoor内部的缓存超时时间配置设置成了30天🙁,而beego自己默认是1小时。

这里又有一个问题,beego里面的session/session.go中不是有manager.provider.SessionExist来查看sid是否存在,不存在的话才创建新的。对的,这个对一般网页上使用的用户来说是没有问题的,因为浏览器会帮你把cookie放到每次的请求中,所以一个用户只用创建一个sid即可,但是这个是应用的请求,取决于编写应用的人有没有把cookie或者sid给你传递过来,如果没有传递就会出现每次请求都有重新创建一个sid和对应的session信息

总结

根据上述的分析,我画出来了整个请求流程图

log

同时得出这次的问题应该是beego框架的问题🤥,但是casdoor也是存在这一些问题的(感觉像是最佳实践)

首先casdoor的缓存设置成立30天,如果用的是file作为sessionProvider,当用户数量多的时候还是会有问题,或者使用redis来做session缓存,至少io性能比磁盘要快,sessionCG时间也快

除了上面的问题,我们在其它地方也发现了一些问题

比如在访问/api/get-groups时,对应的接口在调用的时候没有传分页参数,所以会全查数据表,刚好里面有个获取多条数据,然后循环多条数据并协程查询数据库,那个时候刚好我们弄了很多测试数据,导致该环境下调用该接口就会把数据库连接打满了。后面处理方案应该是更换了其它版本的casdoor,在目前环境的那个版本找不到对应的接口信息了。