fba/models/instances.py

   1 # Fedi API Block - An aggregator for fetching blocking data from fediverse nodes
   2 # Copyright (C) 2023 Free Software Foundation
   3 #
   4 # This program is free software: you can redistribute it and/or modify
   5 # it under the terms of the GNU Affero General Public License as published
   6 # by the Free Software Foundation, either version 3 of the License, or
   7 # (at your option) any later version.
   8 #
   9 # This program is distributed in the hope that it will be useful,
  10 # but WITHOUT ANY WARRANTY; without even the implied warranty of
  11 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  12 # GNU Affero General Public License for more details.
  13 #
  14 # You should have received a copy of the GNU Affero General Public License
  15 # along with this program.  If not, see <https://www.gnu.org/licenses/>.
  16
  17 import logging
  18 import json
  19 import time
  20
  21 import requests
  22 import validators
  23
  24 from fba import database
  25 from fba import utils
  26
  27 from fba.helpers import blacklist
  28 from fba.helpers import cache
  29 from fba.helpers import config
  30 from fba.helpers import domain as domain_helper
  31 from fba.helpers import tidyup
  32
  33 from fba.http import federation
  34 from fba.http import network
  35
  36 from fba.models import error_log
  37
  38 logging.basicConfig(level=logging.INFO)
  39 logger = logging.getLogger(__name__)
  40 #logger.setLevel(logging.DEBUG)
  41
  42 # Found info from node, such as nodeinfo URL, detection mode that needs to be
  43 # written to database. Both arrays must be filled at the same time or else
  44 # update() will fail
  45 _pending = {
  46     # Detection mode
  47     # NULL means all detection methods have failed (maybe still reachable instance)
  48     "detection_mode"     : {},
  49     # Found nodeinfo URL
  50     "nodeinfo_url"       : {},
  51     # Found total peers
  52     "total_peers"        : {},
  53     # Found total blocks
  54     "total_blocks"       : {},
  55     # Obfuscated domains
  56     "obfuscated_blocks"  : {},
  57     # Last fetched instances
  58     "last_instance_fetch": {},
  59     # Last updated
  60     "last_updated"       : {},
  61     # Last blocked
  62     "last_blocked"       : {},
  63     # Last nodeinfo (fetched)
  64     "last_nodeinfo"      : {},
  65     # Last response time
  66     "last_response_time" : {},
  67     # Last status code
  68     "last_status_code"   : {},
  69     # Last error details
  70     "last_error_details" : {},
  71     # Wether obfuscation has been used
  72     "has_obfuscation"    : {},
  73     # Determined software
  74     "software"           : {},
  75 }
  76
  77 def _set_data(key: str, domain: str, value: any):
  78     logger.debug("key='%s',domain='%s',value[]='%s' - CALLED!", key, domain, type(value))
  79     domain_helper.raise_on(domain)
  80
  81     if not isinstance(key, str):
  82         raise ValueError(f"Parameter key[]='{type(key)}' is not of type 'str'")
  83     elif key == "":
  84         raise ValueError("Parameter 'key' is empty")
  85     elif not key in _pending:
  86         raise ValueError(f"key='{key}' not found in _pending")
  87     elif not utils.is_primitive(value):
  88         raise ValueError(f"value[]='{type(value)}' is not a primitive type")
  89
  90     # Set it
  91     _pending[key][domain] = value
  92
  93     logger.debug("EXIT!")
  94
  95 def has_pending(domain: str) -> bool:
  96     logger.debug("domain='%s' - CALLED!", domain)
  97     domain_helper.raise_on(domain)
  98
  99     if not is_registered(domain):
 100         raise ValueError(f"domain='{domain}' is not registered but function was invoked.")
 101
 102     has = False
 103     for key in _pending:
 104         logger.debug("key='%s',domain='%s',_pending[key]()=%d", key, domain, len(_pending[key]))
 105         if domain in _pending[key]:
 106             logger.debug("domain='%s' at key='%s' has pending data ...", domain, key)
 107             has = True
 108             break
 109
 110     logger.debug("has='%s' - EXIT!", has)
 111     return has
 112
 113 def update(domain: str):
 114     logger.debug("domain='%s' - CALLED!", domain)
 115     domain_helper.raise_on(domain)
 116
 117     if not is_registered(domain):
 118         raise Exception(f"domain='{domain}' cannot be updated while not being registered")
 119     elif not has_pending(domain):
 120         raise Exception(f"domain='{domain}' has no pending instance data, but function invoked")
 121
 122     logger.debug("Updating instance data for domain='%s' ...", domain)
 123     sql_string = ""
 124     fields = list()
 125     for key in _pending:
 126         logger.debug("Checking key='%s',domain='%s'", key, domain)
 127         if domain in _pending[key]:
 128             logger.debug("Adding '%s' for key='%s' ...", _pending[key][domain], key)
 129             fields.append(_pending[key][domain])
 130             sql_string += f" {key} = ?,"
 131
 132     logger.debug("sql_string(%d)='%s'", len(sql_string), sql_string)
 133     if sql_string == "":
 134         raise ValueError(f"No fields have been set, but function invoked, domain='{domain}'")
 135
 136     # Set last_updated to current timestamp
 137     fields.append(time.time())
 138
 139     # For WHERE statement
 140     logger.debug("Setting domain='%s' for WHERE statement ...", domain)
 141     fields.append(domain)
 142
 143     logger.debug("sql_string='%s',fields()=%d", sql_string, len(fields))
 144     sql_string = "UPDATE instances SET" + sql_string + " last_updated = ? WHERE domain = ? LIMIT 1"
 145
 146     logger.debug("Executing SQL: sql_string='%s',fields()=%d", sql_string, len(fields))
 147     database.cursor.execute(sql_string, fields)
 148
 149     logger.debug("rowcount=%d", database.cursor.rowcount)
 150     if database.cursor.rowcount == 0:
 151         raise Exception(f"Did not update any rows: domain='{domain}',fields()={len(fields)}")
 152
 153     logger.debug("Invoking commit() ...")
 154     database.connection.commit()
 155
 156     logger.debug("Deleting _pending for domain='%s'", domain)
 157     for key in _pending:
 158         logger.debug("domain='%s',key='%s'", domain, key)
 159         if domain in _pending[key]:
 160             logger.debug("Deleting key='%s',domain='%s' ...", key, domain)
 161             del _pending[key][domain]
 162
 163     logger.debug("EXIT!")
 164
 165 def add(domain: str, origin: str, command: str, path: str = None, software: str = None):
 166     logger.debug("domain='%s',origin='%s',command='%s',path='%s',software='%s' - CALLED!", domain, origin, command, path, software)
 167     domain_helper.raise_on(domain)
 168
 169     if not isinstance(origin, str) and origin is not None:
 170         raise ValueError(f"origin[]='{type(origin)}' is not of type 'str'")
 171     elif origin == "":
 172         raise ValueError("Parameter 'origin' is empty")
 173     elif not isinstance(command, str):
 174         raise ValueError(f"command[]='{type(command)}' is not of type 'str'")
 175     elif command == "":
 176         raise ValueError("Parameter 'command' is empty")
 177     elif not isinstance(path, str) and path is not None:
 178         raise ValueError(f"path[]='{type(path)}' is not of type 'str'")
 179     elif path == "":
 180         raise ValueError("Parameter 'path' is empty")
 181     elif not isinstance(software, str) and software is not None:
 182         raise ValueError(f"software[]='{type(software)}' is not of type 'str'")
 183     elif software == "":
 184         raise ValueError("Parameter 'software' is empty")
 185     elif origin is not None and not validators.domain(origin.split("/")[0]):
 186         raise ValueError(f"Bad origin name='{origin}'")
 187     elif blacklist.is_blacklisted(domain):
 188         raise Exception(f"domain='{domain}' is blacklisted, but function invoked")
 189     elif domain.find("/profile/") > 0 or domain.find("/users/") > 0 or (is_registered(domain.split("/")[0]) and domain.find("/c/") > 0):
 190         raise Exception(f"domain='{domain}' is a single user")
 191     elif domain.find("/tag/") > 0:
 192         raise Exception(f"domain='{domain}' is a tag")
 193
 194     if software is None:
 195         try:
 196             logger.debug("domain='%s',origin='%s',command='%s',path='%s'", domain, origin, command, path)
 197             software = federation.determine_software(domain, path)
 198         except network.exceptions as exception:
 199             logger.warning("Exception '%s' during determining software type, domain='%s'", type(exception), domain)
 200             set_last_error(domain, exception)
 201
 202     logger.debug("Determined software='%s'", software)
 203     if software == "lemmy" and domain.find("/c/") > 0:
 204         domain = domain.split("/c/")[0]
 205
 206         logger.debug("domain='%s' - LEMMY /c/ !", domain)
 207         if is_registered(domain):
 208             logger.warning("domain='%s' already registered after cutting off user part. - EXIT!", domain)
 209             return
 210
 211     logger.info("Adding instance domain='%s',origin='%s',software='%s',command='%s'", domain, origin, software, command)
 212     database.cursor.execute(
 213         "INSERT INTO instances (domain, origin, command, hash, software, first_seen) VALUES (?, ?, ?, ?, ?, ?)",
 214         (
 215            domain,
 216            origin,
 217            command,
 218            utils.get_hash(domain),
 219            software,
 220            time.time()
 221         ),
 222     )
 223
 224     logger.debug("Marking domain='%s' as registered.", domain)
 225     cache.set_sub_key("is_registered", domain, True)
 226
 227     logger.debug("Checking if domain='%s' has pending updates ...", domain)
 228     if has_pending(domain):
 229         logger.debug("Flushing updates for domain='%s' ...", domain)
 230         update(domain)
 231
 232     logger.debug("EXIT!")
 233
 234 def set_last_nodeinfo(domain: str):
 235     logger.debug("domain='%s' - CALLED!", domain)
 236     domain_helper.raise_on(domain)
 237
 238     logger.debug("Updating last_nodeinfo for domain='%s'", domain)
 239     _set_data("last_nodeinfo", domain, time.time())
 240
 241     logger.debug("EXIT!")
 242
 243 def set_last_error(domain: str, error: dict):
 244     logger.debug("domain='%s',error[]='%s' - CALLED!", domain, type(error))
 245     domain_helper.raise_on(domain)
 246
 247     logger.debug("error[]='%s' - BEFORE!", type(error))
 248     if isinstance(error, (BaseException, json.decoder.JSONDecodeError)):
 249         error = f"error[{type(error)}]='{str(error)}'"
 250     logger.debug("error[]='%s' - AFTER!", type(error))
 251
 252     if isinstance(error, str):
 253         logger.debug("Setting last_error_details='%s' (str)", error)
 254         _set_data("last_status_code"  , domain, 999)
 255         _set_data("last_error_details", domain, error if error != "" else None)
 256     elif isinstance(error, requests.models.Response):
 257         logger.debug("Setting last_error_details='%s' (Response)", error.reason)
 258         _set_data("last_status_code"  , domain, error.status_code)
 259         _set_data("last_error_details", domain, error.reason if error.reason != "" else None)
 260     elif not isinstance(error, dict):
 261         raise KeyError(f"Cannot handle keys in error[{type(error)}]='{error}'")
 262     elif "status_code" in error and "error_message" in error:
 263         logger.debug("Setting last_error_details='%s' (error_message)", error['error_message'])
 264         _set_data("last_status_code"  , domain, error["status_code"])
 265         _set_data("last_error_details", domain, error["error_message"] if error["error_message"] != "" else None)
 266     elif "json" in error and "error" in error["json"]:
 267         logger.debug("Setting last_error_details='%s' (json,error)", error["json"]["error"])
 268         _set_data("last_status_code"  , domain, error["status_code"])
 269         _set_data("last_error_details", domain, error["json"]["error"] if error["json"]["error"] != "" else None)
 270
 271     logger.debug("Invoking error_log.add(domain='%s',error[]='%s'", domain, type(error))
 272     error_log.add(domain, error)
 273
 274     logger.debug("EXIT!")
 275
 276 def set_success(domain: str):
 277     logger.debug("domain='%s' - CALLED!", domain)
 278     domain_helper.raise_on(domain)
 279
 280     # Set both to success
 281     _set_data("last_status_code"  , domain, 200)
 282     _set_data("last_error_details", domain, None)
 283
 284     logger.debug("EXIT!")
 285
 286 def is_registered(domain: str, skip_raise = False) -> bool:
 287     logger.debug("domain='%s',skip_raise='%s' - CALLED!", domain, skip_raise)
 288     domain_helper.raise_on(domain)
 289
 290     if not isinstance(skip_raise, bool):
 291         raise ValueError(f"skip_raise[]='{type(skip_raise)}' is not type of 'bool'")
 292
 293     if not skip_raise:
 294         domain_helper.raise_on(domain)
 295
 296     logger.debug("domain='%s' - CALLED!", domain)
 297     if not cache.key_exists("is_registered"):
 298         logger.debug("Cache for 'is_registered' not initialized, fetching all rows ...")
 299         database.cursor.execute("SELECT domain FROM instances")
 300
 301         # Check Set all
 302         cache.set_all("is_registered", database.cursor.fetchall(), True)
 303
 304     # Is cache found?
 305     registered = cache.sub_key_exists("is_registered", domain)
 306
 307     logger.debug("registered='%s' - EXIT!", registered)
 308     return registered
 309
 310 def is_recent(domain: str, column: str = "last_instance_fetch") -> bool:
 311     logger.debug("domain='%s',column='%s' - CALLED!", domain, column)
 312     domain_helper.raise_on(domain)
 313
 314     if not isinstance(column, str):
 315         raise ValueError(f"Parameter column[]='{type(column)}' is not of type 'str'")
 316     elif not column.startswith("last_"):
 317         raise ValueError(f"Parameter column='{column}' is not expected")
 318     elif not is_registered(domain):
 319         logger.debug("domain='%s' is not registered, returning False - EXIT!", domain)
 320         return False
 321
 322     key = "recheck_instance"
 323     if column == "last_blocked":
 324         key = "recheck_block"
 325
 326     # Query database
 327     database.cursor.execute(f"SELECT {column} FROM instances WHERE domain = ? LIMIT 1", [domain])
 328
 329     # Fetch row
 330     row = database.cursor.fetchone()
 331
 332     fetched = float(row[column]) if row[column] is not None else 0.0
 333
 334     diff = (time.time() - fetched)
 335
 336     logger.debug("fetched[%s]='%s',key='%s',diff=%f", type(fetched), fetched, key, diff)
 337     recently = bool(diff < config.get(key))
 338
 339     logger.debug("recently='%s' - EXIT!", recently)
 340     return recently
 341
 342 def deobfuscate(char: str, domain: str, blocked_hash: str = None) -> tuple:
 343     logger.debug("char='%s',domain='%s',blocked_hash='%s' - CALLED!", char, domain, blocked_hash)
 344
 345     if not isinstance(char, str):
 346         raise ValueError(f"Parameter char[]='{type(char)}' is not of type 'str'")
 347     elif char == "":
 348         raise ValueError("Parameter 'char' is empty")
 349     elif not char in domain:
 350         raise ValueError(f"char='{char}' not found in domain='{domain}' but function invoked")
 351     elif not isinstance(domain, str):
 352         raise ValueError(f"Parameter domain[]='{type(domain)}'")
 353     elif not isinstance(blocked_hash, str) and blocked_hash is not None:
 354         raise ValueError(f"Parameter blocked_hash[]='{type(blocked_hash)}' is not of type 'str'")
 355
 356     # Init row
 357     row = None
 358
 359     logger.debug("blocked_hash[]='%s'", type(blocked_hash))
 360     if isinstance(blocked_hash, str):
 361         logger.debug("Looking up blocked_hash='%s',domain='%s' ...", blocked_hash, domain)
 362         database.cursor.execute(
 363             "SELECT domain, origin, nodeinfo_url FROM instances WHERE hash = ? OR domain LIKE ? LIMIT 1", [blocked_hash, domain.replace(char, "_")]
 364         )
 365
 366         row = database.cursor.fetchone()
 367         logger.debug("row[]='%s'", type(row))
 368
 369         if row is None:
 370             logger.debug("blocked_hash='%s' not found, trying domain='%s' ...", blocked_hash, domain)
 371             return deobfuscate(char, domain)
 372     elif not domain.startswith("*."):
 373         logger.debug("domain='%s' - BEFORE!", domain)
 374         domain = tidyup.domain(domain)
 375         logger.debug("domain='%s' - AFTER!", domain)
 376
 377         if domain == "":
 378             logger.warning("domain is empty after tidyup - EXIT!")
 379             return None
 380
 381         search = domain.replace(char, "_")
 382
 383         logger.debug("Looking up domain='%s',search='%s' ...", domain, search)
 384         database.cursor.execute(
 385             "SELECT domain, origin, nodeinfo_url FROM instances WHERE domain LIKE ? OR 'https://' || domain LIKE ? ORDER BY rowid LIMIT 1", [search, search]
 386         )
 387
 388         row = database.cursor.fetchone()
 389         logger.debug("row[]='%s'", type(row))
 390
 391     logger.debug("row[]='%s' - EXIT!", type(row))
 392     return row
 393
 394 def set_last_blocked(domain: str):
 395     logger.debug("domain='%s' - CALLED!", domain)
 396     domain_helper.raise_on(domain)
 397
 398     # Set timestamp
 399     _set_data("last_blocked", domain, time.time())
 400     logger.debug("EXIT!")
 401
 402 def set_last_instance_fetch(domain: str):
 403     logger.debug("domain='%s' - CALLED!", domain)
 404     domain_helper.raise_on(domain)
 405
 406     # Set timestamp
 407     _set_data("last_instance_fetch", domain, time.time())
 408     logger.debug("EXIT!")
 409
 410 def set_last_response_time(domain: str, response_time: float):
 411     logger.debug("domain='%s',response_time=%d - CALLED!", domain, response_time)
 412     domain_helper.raise_on(domain)
 413
 414     if not isinstance(response_time, float):
 415         raise ValueError(f"response_time[]='{type(response_time)}' is not of type 'float'")
 416     elif response_time < 0:
 417         raise ValueError(f"response_time={response_time} is below zero")
 418
 419     # Set timestamp
 420     _set_data("last_response_time", domain, response_time)
 421     logger.debug("EXIT!")
 422
 423 def set_total_peers(domain: str, peers: list):
 424     logger.debug("domain='%s',peers()=%d - CALLED!", domain, len(peers))
 425     domain_helper.raise_on(domain)
 426
 427     if not isinstance(peers, list):
 428         raise ValueError(f"Parameter peers[]='{type(peers)}' is not of type 'list'")
 429
 430     # Set timestamp
 431     _set_data("total_peers", domain, len(peers))
 432     logger.debug("EXIT!")
 433
 434 def set_total_blocks(domain: str, blocks: list):
 435     logger.debug("domain='%s',blocks()=%d - CALLED!", domain, len(blocks))
 436     domain_helper.raise_on(domain)
 437
 438     if not isinstance(blocks, list):
 439         raise ValueError(f"Parameter blocks[]='{type(blocks)}' is not of type 'list'")
 440
 441     # Set timestamp
 442     _set_data("total_blocks", domain, len(blocks))
 443     logger.debug("EXIT!")
 444
 445 def set_obfuscated_blocks(domain: str, obfuscated: int):
 446     logger.debug("domain='%s',obfuscated=%d - CALLED!", domain, obfuscated)
 447     domain_helper.raise_on(domain)
 448
 449     if not isinstance(obfuscated, int):
 450         raise ValueError(f"Parameter obfuscated[]='{type(obfuscated)}' is not of type 'int'")
 451     elif obfuscated < 0:
 452         raise ValueError(f"Parameter obfuscated={obfuscated} is not valid")
 453
 454     # Set timestamp
 455     _set_data("obfuscated_blocks", domain, obfuscated)
 456     logger.debug("EXIT!")
 457
 458 def set_nodeinfo_url(domain: str, url: str):
 459     logger.debug("domain='%s',url='%s' - CALLED!", domain, url)
 460     domain_helper.raise_on(domain)
 461
 462     if not isinstance(url, str) and url is not None:
 463         raise ValueError(f"Parameter url[]='{type(url)}' is not of type 'str'")
 464     elif url == "":
 465         raise ValueError("Parameter 'url' is empty")
 466
 467     # Set timestamp
 468     _set_data("nodeinfo_url", domain, url)
 469     logger.debug("EXIT!")
 470
 471 def set_detection_mode(domain: str, mode: str):
 472     logger.debug("domain='%s',mode='%s' - CALLED!", domain, mode)
 473     domain_helper.raise_on(domain)
 474
 475     if not isinstance(mode, str) and mode is not None:
 476         raise ValueError(f"Parameter mode[]='{type(mode)}' is not of type 'str'")
 477     elif mode == "":
 478         raise ValueError("Parameter 'mode' is empty")
 479
 480     # Set timestamp
 481     _set_data("detection_mode", domain, mode)
 482     logger.debug("EXIT!")
 483
 484 def set_has_obfuscation(domain: str, status: bool):
 485     logger.debug("domain='%s',status='%s' - CALLED!", domain, status)
 486     domain_helper.raise_on(domain)
 487
 488     if not isinstance(status, bool):
 489         raise ValueError(f"Parameter status[]='{type(status)}' is not of type 'bool'")
 490
 491     # Set timestamp
 492     _set_data("has_obfuscation", domain, status)
 493     logger.debug("EXIT!")
 494
 495 def set_software(domain: str, software: str):
 496     logger.debug("domain='%s',software='%s' - CALLED!", domain, software)
 497     domain_helper.raise_on(domain)
 498
 499     if not isinstance(software, str) and software is not None:
 500         raise ValueError(f"Parameter software[]='{type(software)}' is not of type 'str'")
 501     elif software == "":
 502         raise ValueError("Parameter 'software' is empty")
 503
 504     # Set timestamp
 505     _set_data("software", domain, software)
 506     logger.debug("EXIT!")
 507
 508 def valid(value: str, column: str) -> bool:
 509     logger.debug("value='%s' - CALLED!", value)
 510     if not isinstance(value, str):
 511         raise ValueError(f"Parameter value[]='{type(value)}' is not of type 'str'")
 512     elif value == "":
 513         raise ValueError("Parameter 'value' is empty")
 514     elif not isinstance(column, str):
 515         raise ValueError(f"Parameter column[]='{type(column)}' is not of type 'str'")
 516     elif column == "":
 517         raise ValueError("Parameter 'column' is empty")
 518
 519     # Query database
 520     database.cursor.execute(
 521         f"SELECT {column} FROM instances WHERE {column} = ? LIMIT 1", [value]
 522     )
 523
 524     is_valid = database.cursor.fetchone() is not None
 525
 526     logger.debug("is_valid='%s' - EXIT!", is_valid)
 527     return is_valid
 528
 529 def translate_idnas(rows: list, column: str):
 530     logger.debug("rows[]='%s' - CALLED!", type(rows))
 531
 532     if not isinstance(rows, list):
 533         raise ValueError("rows[]='{type(rows)}' is not of type 'list'")
 534     elif len(rows) == 0:
 535         raise ValueError("Parameter 'rows' is an empty list")
 536     elif not isinstance(column, str):
 537         raise ValueError(f"column='{type(column)}' is not of type 'str'")
 538     elif column == "":
 539         raise ValueError("Parameter 'column' is empty")
 540     elif column not in ["domain", "origin"]:
 541         raise ValueError(f"column='{column}' is not supported")
 542
 543     logger.info("Checking/converting %d domain names ...", len(rows))
 544     for row in rows:
 545         logger.debug("row[]='%s'", type(row))
 546
 547         translated = row[column].encode("idna").decode("utf-8")
 548         logger.debug("translated='%s',row[%s]='%s'", translated, column, row[column])
 549
 550         if translated != row[column]:
 551             logger.info("Translated row[%s]='%s' to '%s'", column, row[column], translated)
 552             if is_registered(translated, True):
 553                 logger.warning("Deleting row[%s]='%s' as translated='%s' already exist", column, row[column], translated)
 554                 database.cursor.execute(f"DELETE FROM instances WHERE {column} = ? LIMIT 1", [row[column]])
 555             else:
 556                 logger.debug("Updating row[%s]='%s' to translated='%s' ...", column, row[column], translated)
 557                 database.cursor.execute(f"UPDATE instances SET {column} = ? WHERE {column} = ? LIMIT 1", [translated, row[column]])
 558
 559             logger.debug("Invoking commit() ...")
 560             database.connection.commit()
 561
 562     logger.debug("EXIT!")