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"] and "message" in error["json"]["error"]:
 267         logger.debug("Setting last_error_details='%s' (json,error)", error["json"]["error"]["message"])
 268         _set_data("last_status_code"  , domain, error["status_code"])
 269         _set_data("last_error_details", domain, error["json"]["error"]["message"] if error["json"]["error"]["message"] != "" else None)
 270     elif "json" in error and "error" in error["json"]:
 271         logger.debug("Setting last_error_details='%s' (json,error)", error["json"]["error"])
 272         _set_data("last_status_code"  , domain, error["status_code"])
 273         _set_data("last_error_details", domain, error["json"]["error"] if error["json"]["error"] != "" else None)
 274
 275     logger.debug("Invoking error_log.add(domain='%s',error[]='%s'", domain, type(error))
 276     error_log.add(domain, error)
 277
 278     logger.debug("EXIT!")
 279
 280 def set_success(domain: str):
 281     logger.debug("domain='%s' - CALLED!", domain)
 282     domain_helper.raise_on(domain)
 283
 284     # Set both to success
 285     _set_data("last_status_code"  , domain, 200)
 286     _set_data("last_error_details", domain, None)
 287
 288     logger.debug("EXIT!")
 289
 290 def is_registered(domain: str, skip_raise = False) -> bool:
 291     logger.debug("domain='%s',skip_raise='%s' - CALLED!", domain, skip_raise)
 292     domain_helper.raise_on(domain)
 293
 294     if not isinstance(skip_raise, bool):
 295         raise ValueError(f"skip_raise[]='{type(skip_raise)}' is not type of 'bool'")
 296
 297     if not skip_raise:
 298         domain_helper.raise_on(domain)
 299
 300     logger.debug("domain='%s' - CALLED!", domain)
 301     if not cache.key_exists("is_registered"):
 302         logger.debug("Cache for 'is_registered' not initialized, fetching all rows ...")
 303         database.cursor.execute("SELECT domain FROM instances")
 304
 305         # Check Set all
 306         cache.set_all("is_registered", database.cursor.fetchall(), True)
 307
 308     # Is cache found?
 309     registered = cache.sub_key_exists("is_registered", domain)
 310
 311     logger.debug("registered='%s' - EXIT!", registered)
 312     return registered
 313
 314 def is_recent(domain: str, column: str = "last_instance_fetch") -> bool:
 315     logger.debug("domain='%s',column='%s' - CALLED!", domain, column)
 316     domain_helper.raise_on(domain)
 317
 318     if not isinstance(column, str):
 319         raise ValueError(f"Parameter column[]='{type(column)}' is not of type 'str'")
 320     elif not column.startswith("last_"):
 321         raise ValueError(f"Parameter column='{column}' is not expected")
 322     elif not is_registered(domain):
 323         logger.debug("domain='%s' is not registered, returning False - EXIT!", domain)
 324         return False
 325
 326     key = "recheck_instance"
 327     if column == "last_blocked":
 328         key = "recheck_block"
 329
 330     # Query database
 331     database.cursor.execute(f"SELECT {column} FROM instances WHERE domain = ? LIMIT 1", [domain])
 332
 333     # Fetch row
 334     row = database.cursor.fetchone()
 335
 336     fetched = float(row[column]) if row[column] is not None else 0.0
 337
 338     diff = (time.time() - fetched)
 339
 340     logger.debug("fetched[%s]='%s',key='%s',diff=%f", type(fetched), fetched, key, diff)
 341     recently = bool(diff < config.get(key))
 342
 343     logger.debug("recently='%s' - EXIT!", recently)
 344     return recently
 345
 346 def deobfuscate(char: str, domain: str, blocked_hash: str = None) -> tuple:
 347     logger.debug("char='%s',domain='%s',blocked_hash='%s' - CALLED!", char, domain, blocked_hash)
 348
 349     if not isinstance(char, str):
 350         raise ValueError(f"Parameter char[]='{type(char)}' is not of type 'str'")
 351     elif char == "":
 352         raise ValueError("Parameter 'char' is empty")
 353     elif not char in domain:
 354         raise ValueError(f"char='{char}' not found in domain='{domain}' but function invoked")
 355     elif not isinstance(domain, str):
 356         raise ValueError(f"Parameter domain[]='{type(domain)}'")
 357     elif not isinstance(blocked_hash, str) and blocked_hash is not None:
 358         raise ValueError(f"Parameter blocked_hash[]='{type(blocked_hash)}' is not of type 'str'")
 359
 360     # Init row
 361     row = None
 362
 363     logger.debug("blocked_hash[]='%s'", type(blocked_hash))
 364     if isinstance(blocked_hash, str):
 365         logger.debug("Looking up blocked_hash='%s',domain='%s' ...", blocked_hash, domain)
 366         database.cursor.execute(
 367             "SELECT domain, origin, nodeinfo_url FROM instances WHERE hash = ? OR domain LIKE ? LIMIT 1", [blocked_hash, domain.replace(char, "_")]
 368         )
 369
 370         row = database.cursor.fetchone()
 371         logger.debug("row[]='%s'", type(row))
 372
 373         if row is None:
 374             logger.debug("blocked_hash='%s' not found, trying domain='%s' ...", blocked_hash, domain)
 375             return deobfuscate(char, domain)
 376     elif not domain.startswith("*."):
 377         logger.debug("domain='%s' - BEFORE!", domain)
 378         domain = tidyup.domain(domain)
 379         logger.debug("domain='%s' - AFTER!", domain)
 380
 381         if domain == "":
 382             logger.warning("domain is empty after tidyup - EXIT!")
 383             return None
 384
 385         search = domain.replace(char, "_")
 386
 387         logger.debug("Looking up domain='%s',search='%s' ...", domain, search)
 388         database.cursor.execute(
 389             "SELECT domain, origin, nodeinfo_url FROM instances WHERE domain LIKE ? OR 'https://' || domain LIKE ? ORDER BY rowid LIMIT 1", [search, search]
 390         )
 391
 392         row = database.cursor.fetchone()
 393         logger.debug("row[]='%s'", type(row))
 394
 395     logger.debug("row[]='%s' - EXIT!", type(row))
 396     return row
 397
 398 def set_last_blocked(domain: str):
 399     logger.debug("domain='%s' - CALLED!", domain)
 400     domain_helper.raise_on(domain)
 401
 402     # Set timestamp
 403     _set_data("last_blocked", domain, time.time())
 404     logger.debug("EXIT!")
 405
 406 def set_last_instance_fetch(domain: str):
 407     logger.debug("domain='%s' - CALLED!", domain)
 408     domain_helper.raise_on(domain)
 409
 410     # Set timestamp
 411     _set_data("last_instance_fetch", domain, time.time())
 412     logger.debug("EXIT!")
 413
 414 def set_last_response_time(domain: str, response_time: float):
 415     logger.debug("domain='%s',response_time=%d - CALLED!", domain, response_time)
 416     domain_helper.raise_on(domain)
 417
 418     if not isinstance(response_time, float):
 419         raise ValueError(f"response_time[]='{type(response_time)}' is not of type 'float'")
 420     elif response_time < 0:
 421         raise ValueError(f"response_time={response_time} is below zero")
 422
 423     # Set timestamp
 424     _set_data("last_response_time", domain, response_time)
 425     logger.debug("EXIT!")
 426
 427 def set_total_peers(domain: str, peers: list):
 428     logger.debug("domain='%s',peers()=%d - CALLED!", domain, len(peers))
 429     domain_helper.raise_on(domain)
 430
 431     if not isinstance(peers, list):
 432         raise ValueError(f"Parameter peers[]='{type(peers)}' is not of type 'list'")
 433
 434     # Set timestamp
 435     _set_data("total_peers", domain, len(peers))
 436     logger.debug("EXIT!")
 437
 438 def set_total_blocks(domain: str, blocks: list):
 439     logger.debug("domain='%s',blocks()=%d - CALLED!", domain, len(blocks))
 440     domain_helper.raise_on(domain)
 441
 442     if not isinstance(blocks, list):
 443         raise ValueError(f"Parameter blocks[]='{type(blocks)}' is not of type 'list'")
 444
 445     # Set timestamp
 446     _set_data("total_blocks", domain, len(blocks))
 447     logger.debug("EXIT!")
 448
 449 def set_obfuscated_blocks(domain: str, obfuscated: int):
 450     logger.debug("domain='%s',obfuscated=%d - CALLED!", domain, obfuscated)
 451     domain_helper.raise_on(domain)
 452
 453     if not isinstance(obfuscated, int):
 454         raise ValueError(f"Parameter obfuscated[]='{type(obfuscated)}' is not of type 'int'")
 455     elif obfuscated < 0:
 456         raise ValueError(f"Parameter obfuscated={obfuscated} is not valid")
 457
 458     # Set timestamp
 459     _set_data("obfuscated_blocks", domain, obfuscated)
 460     logger.debug("EXIT!")
 461
 462 def set_nodeinfo_url(domain: str, url: str):
 463     logger.debug("domain='%s',url='%s' - CALLED!", domain, url)
 464     domain_helper.raise_on(domain)
 465
 466     if not isinstance(url, str) and url is not None:
 467         raise ValueError(f"Parameter url[]='{type(url)}' is not of type 'str'")
 468     elif url == "":
 469         raise ValueError("Parameter 'url' is empty")
 470
 471     # Set timestamp
 472     _set_data("nodeinfo_url", domain, url)
 473     logger.debug("EXIT!")
 474
 475 def set_detection_mode(domain: str, mode: str):
 476     logger.debug("domain='%s',mode='%s' - CALLED!", domain, mode)
 477     domain_helper.raise_on(domain)
 478
 479     if not isinstance(mode, str) and mode is not None:
 480         raise ValueError(f"Parameter mode[]='{type(mode)}' is not of type 'str'")
 481     elif mode == "":
 482         raise ValueError("Parameter 'mode' is empty")
 483
 484     # Set timestamp
 485     _set_data("detection_mode", domain, mode)
 486     logger.debug("EXIT!")
 487
 488 def set_has_obfuscation(domain: str, status: bool):
 489     logger.debug("domain='%s',status='%s' - CALLED!", domain, status)
 490     domain_helper.raise_on(domain)
 491
 492     if not isinstance(status, bool):
 493         raise ValueError(f"Parameter status[]='{type(status)}' is not of type 'bool'")
 494
 495     # Set timestamp
 496     _set_data("has_obfuscation", domain, status)
 497     logger.debug("EXIT!")
 498
 499 def set_software(domain: str, software: str):
 500     logger.debug("domain='%s',software='%s' - CALLED!", domain, software)
 501     domain_helper.raise_on(domain)
 502
 503     if not isinstance(software, str) and software is not None:
 504         raise ValueError(f"Parameter software[]='{type(software)}' is not of type 'str'")
 505     elif software == "":
 506         raise ValueError("Parameter 'software' is empty")
 507
 508     # Set timestamp
 509     _set_data("software", domain, software)
 510     logger.debug("EXIT!")
 511
 512 def valid(value: str, column: str) -> bool:
 513     logger.debug("value='%s' - CALLED!", value)
 514     if not isinstance(value, str):
 515         raise ValueError(f"Parameter value[]='{type(value)}' is not of type 'str'")
 516     elif value == "":
 517         raise ValueError("Parameter 'value' is empty")
 518     elif not isinstance(column, str):
 519         raise ValueError(f"Parameter column[]='{type(column)}' is not of type 'str'")
 520     elif column == "":
 521         raise ValueError("Parameter 'column' is empty")
 522
 523     # Query database
 524     database.cursor.execute(
 525         f"SELECT {column} FROM instances WHERE {column} = ? LIMIT 1", [value]
 526     )
 527
 528     is_valid = database.cursor.fetchone() is not None
 529
 530     logger.debug("is_valid='%s' - EXIT!", is_valid)
 531     return is_valid
 532
 533 def translate_idnas(rows: list, column: str):
 534     logger.debug("rows[]='%s' - CALLED!", type(rows))
 535
 536     if not isinstance(rows, list):
 537         raise ValueError("rows[]='{type(rows)}' is not of type 'list'")
 538     elif len(rows) == 0:
 539         raise ValueError("Parameter 'rows' is an empty list")
 540     elif not isinstance(column, str):
 541         raise ValueError(f"column='{type(column)}' is not of type 'str'")
 542     elif column == "":
 543         raise ValueError("Parameter 'column' is empty")
 544     elif column not in ["domain", "origin"]:
 545         raise ValueError(f"column='{column}' is not supported")
 546
 547     logger.info("Checking/converting %d domain names ...", len(rows))
 548     for row in rows:
 549         logger.debug("row[]='%s'", type(row))
 550
 551         translated = row[column].encode("idna").decode("utf-8")
 552         logger.debug("translated='%s',row[%s]='%s'", translated, column, row[column])
 553
 554         if translated != row[column]:
 555             logger.info("Translated row[%s]='%s' to '%s'", column, row[column], translated)
 556             if is_registered(translated, True):
 557                 logger.warning("Deleting row[%s]='%s' as translated='%s' already exist", column, row[column], translated)
 558                 database.cursor.execute(f"DELETE FROM instances WHERE {column} = ? LIMIT 1", [row[column]])
 559             else:
 560                 logger.debug("Updating row[%s]='%s' to translated='%s' ...", column, row[column], translated)
 561                 database.cursor.execute(f"UPDATE instances SET {column} = ? WHERE {column} = ? LIMIT 1", [translated, row[column]])
 562
 563             logger.debug("Invoking commit() ...")
 564             database.connection.commit()
 565
 566     logger.debug("EXIT!")