Zero is invalid as setex "seconds" argument.

[rebeccacremona]

A few dozen times a day, Perma's self-hosted instances of Webrecorder attempt to run Session._update_redis_and_cookie just as a given session's ttl == 0, which causes this line to raise redis.exceptions.ResponseError, since 0 is not a valid value for SETEX's "seconds" argument.

This PR tweaks the existing check, if ttl < 0: ttl = duration, to handle ttl == 0 as well.

Sample Stack Trace

Note: the exception appears to be raised by line 399 rather than 392 because of the "redis pipeline" context manager, which executes all collected redis commands as the context is exited. In this case, the context is being exited after 399, causing the SETEX command issued at 392 to actually execute, and raising the exception.

    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         | Traceback (most recent call last):
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/bottle.py", line 960, in wsgi
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     start_response(response._status_line, response.headerlist)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "./webrecorder/cookieguard.py", line 14, in guard_start_response
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     self.prepare_response(environ, headers)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "./webrecorder/session.py", line 357, in prepare_response
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     self._update_redis_and_cookie(set_cookie, session, headers)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "./webrecorder/session.py", line 399, in _update_redis_and_cookie
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     pi.expire(session.key, duration)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/contextlib.py", line 119, in __exit__
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     next(self.gen)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "./webrecorder/utils.py", line 127, in redis_pipeline
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     p.execute()
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 2879, in execute
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     return execute(conn, stack, raise_on_error)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 2821, in _execute_pipeline
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     self.raise_first_error(commands, response)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 2828, in raise_first_error
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     raise r
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 2816, in _execute_pipeline
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     self.parse_response(connection, args[0], **options))
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 2838, in parse_response
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     self, connection, command_name, **options)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 680, in parse_response
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     response = connection.read_response()
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/connection.py", line 629, in read_response
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     raise response
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         | redis.exceptions.ResponseError: Command # 1 (SETEX sesh:lZCkrvY9Ud24FEIYkBjn3E9n6xY= 0 b'gAN9cQBYAgAAAGlkcQFYHAAAAGxaQ2tydlk5VWQyNEZFSVlrQmpuM0U5bjZ4WT1xAnMu') of pipeline caused error: invalid expire time in setex
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         | During handling of the above exception, another exception occurred:
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         | Traceback (most recent call last):
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/wsgiprox/wsgiprox.py", line 428, in __call__
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     return self.wsgi(env, start_response)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/wsgiprox/wsgiprox.py", line 417, in wsgi
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     return self._wsgi(env, start_response)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "./webrecorder/cookieguard.py", line 18, in __call__
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     return self.app(environ, guard_start_response)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/bottle.py", line 979, in __call__
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     return self.wsgi(environ, start_response)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/bottle.py", line 974, in wsgi
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     start_response('500 INTERNAL SERVER ERROR', headers, sys.exc_info())
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "./webrecorder/cookieguard.py", line 14, in guard_start_response
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     self.prepare_response(environ, headers)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "./webrecorder/session.py", line 357, in prepare_response
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     self._update_redis_and_cookie(set_cookie, session, headers)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "./webrecorder/session.py", line 399, in _update_redis_and_cookie
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     pi.expire(session.key, duration)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/contextlib.py", line 119, in __exit__
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     next(self.gen)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "./webrecorder/utils.py", line 127, in redis_pipeline
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     p.execute()
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 2879, in execute
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     return execute(conn, stack, raise_on_error)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 2821, in _execute_pipeline
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     self.raise_first_error(commands, response)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 2828, in raise_first_error
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     raise r
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 2816, in _execute_pipeline
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     self.parse_response(connection, args[0], **options))
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 2838, in parse_response
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     self, connection, command_name, **options)
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/client.py", line 680, in parse_response
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     response = connection.read_response()
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |   File "/usr/local/lib/python3.7/site-packages/redis/connection.py", line 629, in read_response
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         |     raise response
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: app_1         | redis.exceptions.ResponseError: Command # 1 (SETEX sesh:lZCkrvY9Ud24FEIYkBjn3E9n6xY= 0 b'gAN9cQBYAgAAAGlkcQFYHAAAAGxaQ2tydlk5VWQyNEZFSVlrQmpuM0U5bjZ4WT1xAnMu') of pipeline caused error: invalid expire time in setex
    May 30 15:21:32 ip-172-31-48-6 docker-compose[644]: nginx_1       | 2019/05/30 15:21:32 [error] 6#6: *506021 upstream prematurely closed connection while reading response header from upstream, client: 172.69.6.24, server: wr-prod-004.perma-archives.org, request: "POST /public/7zy8-26r2/20190530151509mp_///analytics.firespring.com/in.php?site_id=100990792&type=ping&mime=js&x=0.26609224965706446 HTTP/1.1", upstream: "uwsgi://172.18.0.4:8081", host: "wr.perma-archives.org", referrer: "https://wr.perma-archives.org/public/7zy8-26r2/20190530151507mp_/https://thebluebench.org/learn/common-misconceptions.html"

Testing

I did not see an appropriate place to add a test for this behavior, but am happy to add one, if advised where you'd like it :-)