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