citadel/docs/logging.txt

   1 =====Logging =====
   2 Note: the logging scheme is not yet persistant all over the citserver.
   3
   4 citadel server has several components that emmit different log strings. Its designed so you can filter for specific sessions.
   5
   6 Since there are several sources for numbering schemes, several numbers need to be employed to make one job / session completely traceable.
   7 The syntax is in general like CC[%d]
   8
   9
  10 === CC - Citadel Context ===
  11 All contexts that are visible to the RWHO command have a citadel context.  The ID of such a context is generated from a source that can grow and shrink again. Thus CC may not be uniq to one session.
  12
  13 Citadel may have several kind of sessions:
  14   - sessions generated by external connections; they have a CC.
  15   - sessions spawned by repetive tasks; they at first may have their own id-range, then later on an IO (AsyncIO) and CC (Citadel Context)
  16
  17 === Identifieing running sessions ===
  18 The RWHO command will list you the currently active CCs:
  19
  20 # sendcommand RWHO
  21 sendcommand: started (pid=14528) connecting to Citadel server at /var/run/citadel/citadel-admin.socket
  22 200 potzblitz Citadel server ADMIN CONNECTION ready.
  23 RWHO
  24 100
  25 576|SYS_rssclient||http://xkcd.org/rss.xml||0||.||||0
  26 1965|willi|Mail|PotzBlitz|IMAP session|1346695500|    |.||||1
  27 sendcommand: processing ended.
  28
  29 576 is the CC connected to this client. with
  30
  31 grep 'CC\[576\]' /var/log/syslog
  32
  33 will show you the loglines from all contexts that had the ID 576; the one named above is an RSS aggregator:
  34
  35 Jul  3 09:07:01 PotzBlitz citserver[1435]: EVCURL:IO[576]CC[576] error description: The requested URL returned error: 404
  36 Jul  3 09:07:01 PotzBlitz citserver[1435]: EVCURL:IO[576]CC[576] error performing request: HTTP response code said error
  37 Jul  3 09:07:01 PotzBlitz citserver[1435]: IO[576]CC[576][29]RSSPneed a 200, got a 404 !
  38
  39
  40 grep 'CC\[1965\]' /var/log/syslog
  41 will show you the loglines from all contexts that had the ID 1965; the one named above is an inbound IMAP Connection:
  42
  43 Jul  3 09:05:01 PotzBlitz citserver[12826]: IMAPCC[1965] <plain_auth>
  44 Jul  3 09:05:01 PotzBlitz citserver[12826]: CC[1965]<Lobby> 144 new of 144 total messages
  45 Jul  3 09:05:02 PotzBlitz citserver[12826]: CC[1965]<0000000010.Mail> 1 new of 17 total messages
  46
  47 === Numbering and prefixes ===
  48
  49 While external sessions will constantly show the same CC (or maybe add their own name space as above with IMAPCC) Its important to understand that not all numbers are available in all situations with sessions from repetive tasks; thus you may need several filters to gather all logmessages belonging to one job.
  50
  51 Generaly once per minute one worker becomes an housekeeping thread; This housekeeper scans the whole system for jobs to start.
  52 Once a job is identified, its detection is logged; neither a CC nor IO are already assigned to this job yet;
  53 but it already has its uniq number assigned to it which is specific to the type of task.
  54 After the preanalysis of this job is done, it may become an AsyncIO job with a Citadel Context. The job now lives in one of the eventqueues, waiting for external file IO or Database IO or performing some calculation of a new state.
  55 Some basic IO debug logging may not facilitate the CC or the Job-ID; especialy during HTTP or DNS requests.
  56
  57 === Debug logging ===
  58 By default citserver will only log information about errors or traffic analysis related errors. If you want to track all a job does, you can enable more logging:
  59
  60 sendcommand LOGP (LOG Print; show status of logs; the following list may increase over time) :
  61
  62 sendcommand: started (pid=19897) connecting to Citadel server at /var/run/citadel/citadel-admin.socket
  63 200 potzblitz Citadel server ADMIN CONNECTION ready.
  64 LOGP
  65 100 Log modules enabled:
  66 modules|0 <- module loading; unloading etc.
  67
  68 rssclient|0  <- RSS aggregator client debugging; on message level
  69 RSSAtomParser|0 <- debugging the parsing of ATOM / RSS feeds; once a message is isolated, the above logging comes into place again.
  70 curl|0 <- HTTP request logging; i.e. querieing the external RSS resources by http is logged with this.
  71
  72 networkqueue|0 <- working through rooms, finding jobs to schedule; reading network spool files, writing them; etc.
  73 networktalkingto|0 <- locked list of network interconnections to circumvent race conditions by simultaneous spooling / sending / receiving
  74 networkclient|0 <- outbound networking connections; this has an IO context.
  75
  76 cares|0 <- asynchroneous nameserver lookup
  77 eventloop|0 <- adding jobs; connecting; timeouts; etc.
  78 eventloopbacktrace|0 <- add stacktraces in certain places; very noisy.
  79
  80 sieve|0 <- sieve filtering of mailboxes
  81 messages|0 <- message processing; loading / printing / saving
  82
  83 imapsrv|0 <- Imap connections
  84 serv_xmpp|0 <- XMPP connections
  85 pop3client|0 <- pop3 aggregators
  86
  87 smtpeventclient|0 <- outbound SMTP connections
  88
  89 sendcommand: processing ended.
  90
  91 If the second column is 1, that debug log is enabled.
  92
  93 You can enable the logging by 3 ways:
  94  - sendcommand 'LOGS cares|1' (live)
  95  - via webcit->aide->Enable/Disable logging of the server components; in an interactive manner
  96  - via environment variable 'CITADEL_LOGDEBUG' as a coma separated list of facilities to enable; before starting citserver
  97  - via commandline parameter '-x' as a coma separated list of facilities to enable; please note that this switch used to set the loglevel previously.
  98
  99
 100
 101 eventloop,eventloopbacktrace,cares
 102   - IO the AsyncIO ID
 103   - IOQ (Queueing of events into eventqueues)
 104
 105 modules:
 106   - modules - module init / registering specific stuff
 107
 108 smtpeventclient
 109   - S[QueueID][N] where the Queue-ID is the number of the Message to be sent, and N the SMTP-job-ID
 110   - SMTPCQ infrastructure logging when the housekeeper is checking for SMTP-Delivery jobs to spawn
 111
 112 imapsrv
 113   - IMAPCC: imap client contexts; commands sent to us from Imap-Clients
 114
 115
 116 networkqueue
 117   - CC -
 118
 119 networkclient
 120   - CC, IO - the context
 121   - NW[nodename][networkerid] the name of the node we're trying to talk to; the networker connection counter uniq per attempt
 122
 123 curl
 124   - CURL - logging where we don't have a context
 125   - CC, IO - the context
 126
 127 RSSClient
 128   - IO, CC, N, 'RSS'; IO & CC not always available.
 129   - 'RSSP' - the rss and atom parser
 130
 131
 132 pop3client
 133   - POP3 IO, CC, N - N the number of that connection
 134
 135 sieve
 136   - sieve doesn't have CC or IOs, its just ran one at a time serverwide.
 137
 138
 139 xmpp
 140   - XMPP - whether CC could & should be logged has to be researched and added.
 141
 142 Context
 143   - 'Context:' context related logging - server infrastructure, cleanup of contexts etc.
 144
 145 messages
 146   - MSG - CC - the context that is manipulating this message.
 147
 148
 149