Add support for log levels

This commit is contained in:
Omar Roth 2019-06-07 20:07:55 -05:00
parent 8c944815bc
commit 58995bb3a2
No known key found for this signature in database
GPG Key ID: B8254FB7EC3D37F2
4 changed files with 60 additions and 19 deletions

View File

@ -382,7 +382,7 @@ get "/watch" do |env|
next env.redirect "/watch?v=#{ex.message}" next env.redirect "/watch?v=#{ex.message}"
rescue ex rescue ex
error_message = ex.message error_message = ex.message
logger.write("#{id} : #{ex.message}\n") logger.puts("#{id} : #{ex.message}")
next templated "error" next templated "error"
end end
@ -2653,7 +2653,7 @@ post "/feed/webhook/:token" do |env|
signature = env.request.headers["X-Hub-Signature"].lchop("sha1=") signature = env.request.headers["X-Hub-Signature"].lchop("sha1=")
if signature != OpenSSL::HMAC.hexdigest(:sha1, HMAC_KEY, body) if signature != OpenSSL::HMAC.hexdigest(:sha1, HMAC_KEY, body)
logger.write("#{token} : Invalid signature\n") logger.puts("#{token} : Invalid signature")
env.response.status_code = 200 env.response.status_code = 200
next next
end end

View File

@ -522,7 +522,7 @@ def analyze_table(db, logger, table_name, struct_type = nil)
begin begin
db.exec("SELECT * FROM #{table_name} LIMIT 0") db.exec("SELECT * FROM #{table_name} LIMIT 0")
rescue ex rescue ex
logger.write("CREATE TABLE #{table_name}\n") logger.puts("CREATE TABLE #{table_name}")
db.using_connection do |conn| db.using_connection do |conn|
conn.as(PG::Connection).exec_all(File.read("config/sql/#{table_name}.sql")) conn.as(PG::Connection).exec_all(File.read("config/sql/#{table_name}.sql"))
@ -546,7 +546,7 @@ def analyze_table(db, logger, table_name, struct_type = nil)
if name != column_array[i]? if name != column_array[i]?
if !column_array[i]? if !column_array[i]?
new_column = column_types.select { |line| line.starts_with? name }[0] new_column = column_types.select { |line| line.starts_with? name }[0]
logger.write("ALTER TABLE #{table_name} ADD COLUMN #{new_column}\n") logger.puts("ALTER TABLE #{table_name} ADD COLUMN #{new_column}")
db.exec("ALTER TABLE #{table_name} ADD COLUMN #{new_column}") db.exec("ALTER TABLE #{table_name} ADD COLUMN #{new_column}")
next next
end end
@ -564,26 +564,29 @@ def analyze_table(db, logger, table_name, struct_type = nil)
# There's a column we didn't expect # There's a column we didn't expect
if !new_column if !new_column
logger.write("ALTER TABLE #{table_name} DROP COLUMN #{column_array[i]}\n") logger.puts("ALTER TABLE #{table_name} DROP COLUMN #{column_array[i]}")
db.exec("ALTER TABLE #{table_name} DROP COLUMN #{column_array[i]} CASCADE") db.exec("ALTER TABLE #{table_name} DROP COLUMN #{column_array[i]} CASCADE")
column_array = get_column_array(db, table_name) column_array = get_column_array(db, table_name)
next next
end end
logger.write("ALTER TABLE #{table_name} ADD COLUMN #{new_column}\n") logger.puts("ALTER TABLE #{table_name} ADD COLUMN #{new_column}")
db.exec("ALTER TABLE #{table_name} ADD COLUMN #{new_column}") db.exec("ALTER TABLE #{table_name} ADD COLUMN #{new_column}")
logger.write("UPDATE #{table_name} SET #{column_array[i]}_new=#{column_array[i]}\n")
logger.puts("UPDATE #{table_name} SET #{column_array[i]}_new=#{column_array[i]}")
db.exec("UPDATE #{table_name} SET #{column_array[i]}_new=#{column_array[i]}") db.exec("UPDATE #{table_name} SET #{column_array[i]}_new=#{column_array[i]}")
logger.write("ALTER TABLE #{table_name} DROP COLUMN #{column_array[i]} CASCADE\n")
logger.puts("ALTER TABLE #{table_name} DROP COLUMN #{column_array[i]} CASCADE")
db.exec("ALTER TABLE #{table_name} DROP COLUMN #{column_array[i]} CASCADE") db.exec("ALTER TABLE #{table_name} DROP COLUMN #{column_array[i]} CASCADE")
logger.write("ALTER TABLE #{table_name} RENAME COLUMN #{column_array[i]}_new TO #{column_array[i]}\n")
logger.puts("ALTER TABLE #{table_name} RENAME COLUMN #{column_array[i]}_new TO #{column_array[i]}")
db.exec("ALTER TABLE #{table_name} RENAME COLUMN #{column_array[i]}_new TO #{column_array[i]}") db.exec("ALTER TABLE #{table_name} RENAME COLUMN #{column_array[i]}_new TO #{column_array[i]}")
column_array = get_column_array(db, table_name) column_array = get_column_array(db, table_name)
end end
else else
logger.write("ALTER TABLE #{table_name} DROP COLUMN #{column_array[i]} CASCADE\n") logger.puts("ALTER TABLE #{table_name} DROP COLUMN #{column_array[i]} CASCADE")
db.exec("ALTER TABLE #{table_name} DROP COLUMN #{column_array[i]} CASCADE") db.exec("ALTER TABLE #{table_name} DROP COLUMN #{column_array[i]} CASCADE")
end end
end end

View File

@ -27,7 +27,7 @@ def refresh_channels(db, logger, config)
if ex.message == "Deleted or invalid channel" if ex.message == "Deleted or invalid channel"
db.exec("UPDATE channels SET updated = $1, deleted = true WHERE id = $2", Time.utc, id) db.exec("UPDATE channels SET updated = $1, deleted = true WHERE id = $2", Time.utc, id)
end end
logger.write("#{id} : #{ex.message}\n") logger.puts("#{id} : #{ex.message}")
end end
active_channel.send(true) active_channel.send(true)
@ -68,14 +68,14 @@ def refresh_feeds(db, logger, config)
column_array = get_column_array(db, view_name) column_array = get_column_array(db, view_name)
ChannelVideo.to_type_tuple.each_with_index do |name, i| ChannelVideo.to_type_tuple.each_with_index do |name, i|
if name != column_array[i]? if name != column_array[i]?
logger.write("DROP MATERIALIZED VIEW #{view_name}\n") logger.puts("DROP MATERIALIZED VIEW #{view_name}")
db.exec("DROP MATERIALIZED VIEW #{view_name}") db.exec("DROP MATERIALIZED VIEW #{view_name}")
raise "view does not exist" raise "view does not exist"
end end
end end
if db.query_one("SELECT pg_get_viewdef('#{view_name}')", as: String).includes? "ucid = ANY" if db.query_one("SELECT pg_get_viewdef('#{view_name}')", as: String).includes? "ucid = ANY"
logger.write("Materialized view #{view_name} is out-of-date, recreating...\n") logger.puts("Materialized view #{view_name} is out-of-date, recreating...")
db.exec("DROP MATERIALIZED VIEW #{view_name}") db.exec("DROP MATERIALIZED VIEW #{view_name}")
end end
@ -87,13 +87,13 @@ def refresh_feeds(db, logger, config)
legacy_view_name = "subscriptions_#{sha256(email)[0..7]}" legacy_view_name = "subscriptions_#{sha256(email)[0..7]}"
db.exec("SELECT * FROM #{legacy_view_name} LIMIT 0") db.exec("SELECT * FROM #{legacy_view_name} LIMIT 0")
logger.write("RENAME MATERIALIZED VIEW #{legacy_view_name}\n") logger.puts("RENAME MATERIALIZED VIEW #{legacy_view_name}")
db.exec("ALTER MATERIALIZED VIEW #{legacy_view_name} RENAME TO #{view_name}") db.exec("ALTER MATERIALIZED VIEW #{legacy_view_name} RENAME TO #{view_name}")
rescue ex rescue ex
begin begin
# While iterating through, we may have an email stored from a deleted account # While iterating through, we may have an email stored from a deleted account
if db.query_one?("SELECT true FROM users WHERE email = $1", email, as: Bool) if db.query_one?("SELECT true FROM users WHERE email = $1", email, as: Bool)
logger.write("CREATE #{view_name}\n") logger.puts("CREATE #{view_name}")
db.exec("CREATE MATERIALIZED VIEW #{view_name} AS \ db.exec("CREATE MATERIALIZED VIEW #{view_name} AS \
SELECT * FROM channel_videos WHERE SELECT * FROM channel_videos WHERE
ucid IN (SELECT unnest(subscriptions) FROM users WHERE email = E'#{email.gsub("'", "\\'")}') ucid IN (SELECT unnest(subscriptions) FROM users WHERE email = E'#{email.gsub("'", "\\'")}')
@ -101,7 +101,7 @@ def refresh_feeds(db, logger, config)
db.exec("UPDATE users SET feed_needs_update = false WHERE email = $1", email) db.exec("UPDATE users SET feed_needs_update = false WHERE email = $1", email)
end end
rescue ex rescue ex
logger.write("REFRESH #{email} : #{ex.message}\n") logger.puts("REFRESH #{email} : #{ex.message}")
end end
end end
end end
@ -151,7 +151,7 @@ def subscribe_to_feeds(db, logger, key, config)
response = subscribe_pubsub(ucid, key, config) response = subscribe_pubsub(ucid, key, config)
if response.status_code >= 400 if response.status_code >= 400
logger.write("#{ucid} : #{response.body}\n") logger.puts("#{ucid} : #{response.body}")
end end
rescue ex rescue ex
end end

View File

@ -1,7 +1,14 @@
require "logger" require "logger"
enum LogLevel
Debug
Info
Warn
Error
end
class Invidious::LogHandler < Kemal::BaseLogHandler class Invidious::LogHandler < Kemal::BaseLogHandler
def initialize(@io : IO = STDOUT) def initialize(@io : IO = STDOUT, @level = LogLevel::Warn)
end end
def call(context : HTTP::Server::Context) def call(context : HTTP::Server::Context)
@ -18,7 +25,15 @@ class Invidious::LogHandler < Kemal::BaseLogHandler
context context
end end
def write(message : String) def puts(message : String)
@io << message << '\n'
if @io.is_a? File
@io.flush
end
end
def write(message : String, level = @level)
@io << message @io << message
if @io.is_a? File if @io.is_a? File
@ -26,6 +41,29 @@ class Invidious::LogHandler < Kemal::BaseLogHandler
end end
end end
def set_log_level(level : String)
case level.downcase
when "debug"
set_log_level(LogLevel::Debug)
when "info"
set_log_level(LogLevel::Info)
when "warn"
set_log_level(LogLevel::Warn)
when "error"
set_log_level(LogLevel::Error)
end
end
def set_log_level(level : LogLevel)
@level = level
end
{% for level in %w(debug info warn error) %}
def {{level.id}}(message : String)
puts(message, LogLevel::{{level.id.capitalize}})
end
{% end %}
private def elapsed_text(elapsed) private def elapsed_text(elapsed)
millis = elapsed.total_milliseconds millis = elapsed.total_milliseconds
return "#{millis.round(2)}ms" if millis >= 1 return "#{millis.round(2)}ms" if millis >= 1