Author Topic: Session auth check failed / Send new auth cookie  (Read 1571 times)

Offline mjnewton

  • Newbie
  • *
  • Posts: 6
Session auth check failed / Send new auth cookie
« on: April 23, 2021, 07:18:13 AM »
Environment: Roundcube v1.4.11 (all plugins disabled) running on Raspbian 10 (Debian Buster), Apache 2.4.38, PHP 7.3, SQLite3 DB, Chrome 90.0.4430.85 / Firefox 87.0 browsers

Hi everyone,

I recently noticed that my session.log is full of these entries occurring every 5 minutes continuously during an active user sessions (two users in this case):

Code: [Select]
[23-Apr-2021 11:45:00 +0100]: <f8tuvr6s> Session auth check failed for f8tuvr6snu194rbb25l4tc9mbk; timeslot = 2021-04-23 11:45:00
[23-Apr-2021 11:45:00 +0100]: <f8tuvr6s> Send new auth cookie for f8tuvr6snu194rbb25l4tc9mbk: y8WmBhx2n96UuIJ4gcou3FBrkA-1619174400
[23-Apr-2021 11:45:39 +0100]: <dlgl7kkf> Session auth check failed for dlgl7kkf2gecnlbkn0ioqq25q3; timeslot = 2021-04-23 11:45:00
[23-Apr-2021 11:45:39 +0100]: <dlgl7kkf> Send new auth cookie for dlgl7kkf2gecnlbkn0ioqq25q3: CiGJ51TRyYjR23O8sGOjFNDk3Z-1619174400
[23-Apr-2021 11:50:00 +0100]: <f8tuvr6s> Session auth check failed for f8tuvr6snu194rbb25l4tc9mbk; timeslot = 2021-04-23 11:50:00
[23-Apr-2021 11:50:00 +0100]: <f8tuvr6s> Send new auth cookie for f8tuvr6snu194rbb25l4tc9mbk: y8WmBhx2n96UuIJ4gcou3FBrkA-1619174700
[23-Apr-2021 11:50:39 +0100]: <dlgl7kkf> Session auth check failed for dlgl7kkf2gecnlbkn0ioqq25q3; timeslot = 2021-04-23 11:50:00
[23-Apr-2021 11:50:39 +0100]: <dlgl7kkf> Send new auth cookie for dlgl7kkf2gecnlbkn0ioqq25q3: CiGJ51TRyYjR23O8sGOjFNDk3Z-1619174700
[23-Apr-2021 11:55:00 +0100]: <f8tuvr6s> Session auth check failed for f8tuvr6snu194rbb25l4tc9mbk; timeslot = 2021-04-23 11:55:00
[23-Apr-2021 11:55:00 +0100]: <f8tuvr6s> Send new auth cookie for f8tuvr6snu194rbb25l4tc9mbk: y8WmBhx2n96UuIJ4gcou3FBrkA-1619175000
[23-Apr-2021 11:55:39 +0100]: <dlgl7kkf> Session auth check failed for dlgl7kkf2gecnlbkn0ioqq25q3; timeslot = 2021-04-23 11:55:00
[23-Apr-2021 11:55:39 +0100]: <dlgl7kkf> Send new auth cookie for dlgl7kkf2gecnlbkn0ioqq25q3: CiGJ51TRyYjR23O8sGOjFNDk3Z-1619175000
[23-Apr-2021 12:00:00 +0100]: <f8tuvr6s> Session auth check failed for f8tuvr6snu194rbb25l4tc9mbk; timeslot = 2021-04-23 12:00:00
[23-Apr-2021 12:00:00 +0100]: <f8tuvr6s> Send new auth cookie for f8tuvr6snu194rbb25l4tc9mbk: y8WmBhx2n96UuIJ4gcou3FBrkA-1619175300
[23-Apr-2021 12:00:39 +0100]: <dlgl7kkf> Session auth check failed for dlgl7kkf2gecnlbkn0ioqq25q3; timeslot = 2021-04-23 12:00:00
[23-Apr-2021 12:00:39 +0100]: <dlgl7kkf> Send new auth cookie for dlgl7kkf2gecnlbkn0ioqq25q3: CiGJ51TRyYjR23O8sGOjFNDk3Z-1619175300
[23-Apr-2021 12:05:00 +0100]: <f8tuvr6s> Session auth check failed for f8tuvr6snu194rbb25l4tc9mbk; timeslot = 2021-04-23 12:05:00
[23-Apr-2021 12:05:00 +0100]: <f8tuvr6s> Send new auth cookie for f8tuvr6snu194rbb25l4tc9mbk: y8WmBhx2n96UuIJ4gcou3FBrkA-1619175600
[23-Apr-2021 12:05:39 +0100]: <dlgl7kkf> Session auth check failed for dlgl7kkf2gecnlbkn0ioqq25q3; timeslot = 2021-04-23 12:05:00
[23-Apr-2021 12:05:39 +0100]: <dlgl7kkf> Send new auth cookie for dlgl7kkf2gecnlbkn0ioqq25q3: CiGJ51TRyYjR23O8sGOjFNDk3Z-1619175600

Notwithstanding these entries (which I am assuming are an 'error' of some sort given the 'fail' terminology?) everything appears to be working perfectly fine with no issues whatsoever. I was however wondering:

1) Do others with a working system also see these entries. The reason I say 'working' is because I've seen lots of references to these entries in other threads but it has always been in relation, and a slight aside, to some very real problem the a solution is being sought. Such threads have either not concluded or have ended up with a fix for the main problem but no mention as to whether these log entries went away as a result.

2) Is it an issue? As I say, everything appears to be working just fine so if it wasn't for the logging I doubt I'd be any the wiser about them.

Something of interest, and potential relevance, is that as you can see the timestamps are always consistent - they are always at ~5 minute intervals and always at whole 5 minute past the hour (e.g. xx:00, xx:05, xx:10 etc). Could this be a clue as to what's responsible for the 'session auth check fail[ure]'? I'm wondering if there's a system activity that's behind it i.e. Roundcube is the 'victim' rather than the 'cause', if you see what I mean.

Grateful to hear your thoughts...
« Last Edit: April 23, 2021, 08:08:07 AM by mjnewton »

Offline mjnewton

  • Newbie
  • *
  • Posts: 6
Re: Session auth check failed / Send new auth cookie
« Reply #1 on: April 24, 2021, 06:59:39 AM »
To follow-up; having reached the point where I was reasonably satisfied I didn't have a system installation/configuration problem I raised an issue and it's been confirmed that the entries are actually expected behaviour, which would explain why everything appeared to be working fine. Obviously if others entries appear alongside them then that's a different issue.
« Last Edit: April 24, 2021, 07:49:13 AM by mjnewton »