filters/log/nbdkit-log-filter.pod

   1 =head1 NAME
   2
   3 nbdkit-log-filter - nbdkit log filter
   4
   5 =head1 SYNOPSIS
   6
   7  nbdkit --filter=log PLUGIN
   8                      [logfile=FILE | logscript=SCRIPT] [logappend=BOOL]
   9                      [PLUGIN-ARGS...]
  10
  11 =head1 DESCRIPTION
  12
  13 C<nbdkit-log-filter> is a filter that logs all transactions to a file
  14 or external script.
  15
  16 When used as the first filter, it can show the original client
  17 requests.  As a later filter, it can show how earlier filters have
  18 modified the original request.
  19
  20 When using C<logfile=FILE>, logs are written to a log file with the
  21 format described in L</LOG FILE FORMAT> below.
  22
  23 When using C<logscript=SCRIPT>, logs invoke the external script.  See
  24 L</LOG SCRIPT> below.
  25
  26 An alternative to this filter is simply to run nbdkit with the I<-f>
  27 and I<-v> flags which enable verbose debugging to stderr.  This logs
  28 many aspects of nbdkit operation, but requires running nbdkit in the
  29 foreground.  The log filter uses a more parsimonious and more easily
  30 parsable format and works when nbdkit runs in the background.
  31
  32 =head1 PARAMETERS
  33
  34 C<logfile> or C<logscript> or both can be given.  If neither then the
  35 filter is inactive.
  36
  37 =over 4
  38
  39 =item B<logfile=>FILE
  40
  41 The file where the log is written.  See L</LOG FILE FORMAT> below.
  42
  43 =item B<logscript=>SCRIPT
  44
  45 (nbdkit E<ge> 1.24)
  46
  47 Log lines invoke an external script.  See L</LOG SCRIPT> below.
  48
  49 =item B<logappend=true>
  50
  51 =item B<logappend=false>
  52
  53 (nbdkit E<ge> 1.8)
  54
  55 This only affects C<logfile>.  If C<false> (the default), if the file
  56 already exists it will be truncated.  If C<true>, the filter appends
  57 to the existing log file.
  58
  59 =back
  60
  61 =head1 EXAMPLES
  62
  63 Serve the file F<disk.img>, and log each client transaction in the
  64 file F<disk.log>:
  65
  66  nbdkit --filter=log file disk.img logfile=disk.log
  67
  68 Repeat the task, but with the cow (copy-on-write) filter to perform
  69 local caching of data served from the original plugin:
  70
  71  nbdkit --filter=cow --filter=log file disk.img logfile=disk.log2
  72
  73 After running a client that performs the same operations under each of
  74 the two servers, you can compare F<disk.log> and F<disk.log2> to see
  75 the impact of the caching.
  76
  77 =head1 LOG FILE FORMAT
  78
  79 An example logging session of a client that requests an export list
  80 before performing a single successful read is:
  81
  82  2020-08-06 02:07:23.080415 ListExports id=1 readonly=0 tls=0 ...
  83  2020-08-06 02:07:23.080502 ...ListExports id=1 exports=("") return=0
  84  2020-08-06 02:07:23.080712 connection=1 Connect export="" tls=0 size=0x400 minsize=0x1 prefsize=0x200 maxsize=0xffffffff write=1 flush=1 rotational=0 trim=1 zero=2 fua=2 extents=1 cache=2 fast_zero=1
  85  2020-08-06 02:07:23.080907 connection=1 Read id=1 offset=0x0 count=0x200 ...
  86  2020-08-06 02:07:23.080927 connection=1 ...Read id=1 return=0
  87  2020-08-06 02:07:23.081255 connection=1 Disconnect transactions=1
  88
  89 All lines start with a timestamp in C<YYYY-MM-DD HH:MM:ZZ.MS> format.
  90
  91 For connected calls, C<connection=N> is present to distinguish
  92 between clients.
  93
  94 The action follows.  Currently the following actions are logged:
  95 ListExports, Ready, Fork, Preconnect, Connect, Read, Write, Zero,
  96 Trim, Extents, Cache, Flush and Disconnect.
  97
  98 Some actions are logged across two lines showing the call and return
  99 value.  Because nbdkit handles requests in parallel different requests
 100 may be intermingled.  Use the C<id=N> field for correlation, it is
 101 unique per connection.
 102
 103 Strings and lists are shell-quoted.
 104
 105 =head1 LOG SCRIPT
 106
 107 If C<logscript=SCRIPT> is given on the command line then log entries
 108 are passed to the external script.
 109
 110 The script is passed several shell variables:
 111
 112 =over 4
 113
 114 =item C<$act>
 115
 116 The action name, like C<"Read">, C<"Write"> etc.
 117
 118 =item C<$connection>
 119
 120 The connection ID identifying the client, only for connected calls
 121 like C<"Read">.
 122
 123 =item C<$error>
 124
 125 For messages of type C<"LEAVE"> which fail (C<$return = -1>), this
 126 contains the errno as a string, for example C<"EIO">.
 127
 128 =item C<$id>
 129
 130 The transaction ID, used to correlate actions which are split into two
 131 messages C<"ENTER"> and C<"LEAVE">.
 132
 133 =item C<$return>
 134
 135 For messages of type C<"LEAVE"> this is the return code, usually C<0>
 136 for success and C<-1> if there was an error.
 137
 138 =item C<$type>
 139
 140 The message type: C<"ENTER">, C<"LEAVE"> or C<"PRINT">.
 141
 142 =item other shell variables
 143
 144 Other parameters like C<offset=N> are turned into shell variables
 145 C<$offset> etc.
 146
 147 =back
 148
 149 Note the return value of the script is ignored.  Log scripts cannot
 150 modify or interrupt request processing.
 151
 152 =head2 Log script examples
 153
 154 The script:
 155
 156  nbdkit -f --filter=log null 10M \
 157         logscript='echo $connection $type $id $act $offset >&2'
 158
 159 might print lines like:
 160
 161  PRINT Ready
 162  1 ENTER 1 Read 0x0
 163  1 ENTER 2 Write 0x200
 164  1 LEAVE 2 Write
 165  1 LEAVE 1 Read
 166
 167 corresponding to log file lines:
 168
 169  Ready thread_model=3
 170  connection=1 Read id=1 offset=0x0 count=0x200 ...
 171  connection=1 Write id=2 offset=0x200 count=0x200 ...
 172  connection=1 ...Write id=2
 173  connection=1 ...Read id=1
 174
 175 This script will trigger a message when any client reads:
 176
 177  nbdkit -f --filter=log memory 10M \
 178         logscript='
 179             if [ "$act" = "Read" -a "$type" = "ENTER" ]; then
 180                 echo Client is reading $count bytes from $offset >&2
 181             fi
 182         '
 183
 184 =head1 FILES
 185
 186 =over 4
 187
 188 =item C<logfile=FILE> parameter
 189
 190 This filter writes to the file specified by the C<logfile=FILE>
 191 parameter.
 192
 193 =item F<$filterdir/nbdkit-log-filter.so>
 194
 195 The filter.
 196
 197 Use C<nbdkit --dump-config> to find the location of C<$filterdir>.
 198
 199 =back
 200
 201 =head1 VERSION
 202
 203 C<nbdkit-log-filter> first appeared in nbdkit 1.4.
 204
 205 =head1 SEE ALSO
 206
 207 L<nbdkit(1)>,
 208 L<nbdkit-file-plugin(1)>,
 209 L<nbdkit-cow-filter(1)>,
 210 L<nbdkit-filter(3)>,
 211 L<nbdkit-stats-filter(1)>.
 212
 213 =head1 AUTHORS
 214
 215 Eric Blake
 216
 217 =head1 COPYRIGHT
 218
 219 Copyright Red Hat