lib/dpif.c

   1 /*
   2  * Copyright (c) 2008, 2009, 2010, 2011, 2012 Nicira Networks.
   3  *
   4  * Licensed under the Apache License, Version 2.0 (the "License");
   5  * you may not use this file except in compliance with the License.
   6  * You may obtain a copy of the License at:
   7  *
   8  *     http://www.apache.org/licenses/LICENSE-2.0
   9  *
  10  * Unless required by applicable law or agreed to in writing, software
  11  * distributed under the License is distributed on an "AS IS" BASIS,
  12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13  * See the License for the specific language governing permissions and
  14  * limitations under the License.
  15  */
  16
  17 #include <config.h>
  18 #include "dpif-provider.h"
  19
  20 #include <assert.h>
  21 #include <ctype.h>
  22 #include <errno.h>
  23 #include <inttypes.h>
  24 #include <stdlib.h>
  25 #include <string.h>
  26
  27 #include "coverage.h"
  28 #include "dynamic-string.h"
  29 #include "flow.h"
  30 #include "netdev.h"
  31 #include "netlink.h"
  32 #include "odp-util.h"
  33 #include "ofp-errors.h"
  34 #include "ofp-print.h"
  35 #include "ofp-util.h"
  36 #include "ofpbuf.h"
  37 #include "packets.h"
  38 #include "poll-loop.h"
  39 #include "shash.h"
  40 #include "sset.h"
  41 #include "timeval.h"
  42 #include "util.h"
  43 #include "valgrind.h"
  44 #include "vlog.h"
  45
  46 VLOG_DEFINE_THIS_MODULE(dpif);
  47
  48 COVERAGE_DEFINE(dpif_destroy);
  49 COVERAGE_DEFINE(dpif_port_add);
  50 COVERAGE_DEFINE(dpif_port_del);
  51 COVERAGE_DEFINE(dpif_flow_flush);
  52 COVERAGE_DEFINE(dpif_flow_get);
  53 COVERAGE_DEFINE(dpif_flow_put);
  54 COVERAGE_DEFINE(dpif_flow_del);
  55 COVERAGE_DEFINE(dpif_flow_query_list);
  56 COVERAGE_DEFINE(dpif_flow_query_list_n);
  57 COVERAGE_DEFINE(dpif_execute);
  58 COVERAGE_DEFINE(dpif_purge);
  59
  60 static const struct dpif_class *base_dpif_classes[] = {
  61 #ifdef HAVE_NETLINK
  62     &dpif_linux_class,
  63 #endif
  64     &dpif_netdev_class,
  65 };
  66
  67 struct registered_dpif_class {
  68     const struct dpif_class *dpif_class;
  69     int refcount;
  70 };
  71 static struct shash dpif_classes = SHASH_INITIALIZER(&dpif_classes);
  72 static struct sset dpif_blacklist = SSET_INITIALIZER(&dpif_blacklist);
  73
  74 /* Rate limit for individual messages going to or from the datapath, output at
  75  * DBG level.  This is very high because, if these are enabled, it is because
  76  * we really need to see them. */
  77 static struct vlog_rate_limit dpmsg_rl = VLOG_RATE_LIMIT_INIT(600, 600);
  78
  79 /* Not really much point in logging many dpif errors. */
  80 static struct vlog_rate_limit error_rl = VLOG_RATE_LIMIT_INIT(60, 5);
  81
  82 static void log_flow_message(const struct dpif *dpif, int error,
  83                              const char *operation,
  84                              const struct nlattr *key, size_t key_len,
  85                              const struct dpif_flow_stats *stats,
  86                              const struct nlattr *actions, size_t actions_len);
  87 static void log_operation(const struct dpif *, const char *operation,
  88                           int error);
  89 static bool should_log_flow_message(int error);
  90 static void log_flow_put_message(struct dpif *, const struct dpif_flow_put *,
  91                                  int error);
  92 static void log_flow_del_message(struct dpif *, const struct dpif_flow_del *,
  93                                  int error);
  94 static void log_execute_message(struct dpif *, const struct dpif_execute *,
  95                                 int error);
  96
  97 static void
  98 dp_initialize(void)
  99 {
 100     static int status = -1;
 101
 102     if (status < 0) {
 103         int i;
 104
 105         status = 0;
 106         for (i = 0; i < ARRAY_SIZE(base_dpif_classes); i++) {
 107             dp_register_provider(base_dpif_classes[i]);
 108         }
 109     }
 110 }
 111
 112 /* Registers a new datapath provider.  After successful registration, new
 113  * datapaths of that type can be opened using dpif_open(). */
 114 int
 115 dp_register_provider(const struct dpif_class *new_class)
 116 {
 117     struct registered_dpif_class *registered_class;
 118
 119     if (sset_contains(&dpif_blacklist, new_class->type)) {
 120         VLOG_DBG("attempted to register blacklisted provider: %s",
 121                  new_class->type);
 122         return EINVAL;
 123     }
 124
 125     if (shash_find(&dpif_classes, new_class->type)) {
 126         VLOG_WARN("attempted to register duplicate datapath provider: %s",
 127                   new_class->type);
 128         return EEXIST;
 129     }
 130
 131     registered_class = xmalloc(sizeof *registered_class);
 132     registered_class->dpif_class = new_class;
 133     registered_class->refcount = 0;
 134
 135     shash_add(&dpif_classes, new_class->type, registered_class);
 136
 137     return 0;
 138 }
 139
 140 /* Unregisters a datapath provider.  'type' must have been previously
 141  * registered and not currently be in use by any dpifs.  After unregistration
 142  * new datapaths of that type cannot be opened using dpif_open(). */
 143 int
 144 dp_unregister_provider(const char *type)
 145 {
 146     struct shash_node *node;
 147     struct registered_dpif_class *registered_class;
 148
 149     node = shash_find(&dpif_classes, type);
 150     if (!node) {
 151         VLOG_WARN("attempted to unregister a datapath provider that is not "
 152                   "registered: %s", type);
 153         return EAFNOSUPPORT;
 154     }
 155
 156     registered_class = node->data;
 157     if (registered_class->refcount) {
 158         VLOG_WARN("attempted to unregister in use datapath provider: %s", type);
 159         return EBUSY;
 160     }
 161
 162     shash_delete(&dpif_classes, node);
 163     free(registered_class);
 164
 165     return 0;
 166 }
 167
 168 /* Blacklists a provider.  Causes future calls of dp_register_provider() with
 169  * a dpif_class which implements 'type' to fail. */
 170 void
 171 dp_blacklist_provider(const char *type)
 172 {
 173     sset_add(&dpif_blacklist, type);
 174 }
 175
 176 /* Clears 'types' and enumerates the types of all currently registered datapath
 177  * providers into it.  The caller must first initialize the sset. */
 178 void
 179 dp_enumerate_types(struct sset *types)
 180 {
 181     struct shash_node *node;
 182
 183     dp_initialize();
 184     sset_clear(types);
 185
 186     SHASH_FOR_EACH(node, &dpif_classes) {
 187         const struct registered_dpif_class *registered_class = node->data;
 188         sset_add(types, registered_class->dpif_class->type);
 189     }
 190 }
 191
 192 /* Clears 'names' and enumerates the names of all known created datapaths with
 193  * the given 'type'.  The caller must first initialize the sset.  Returns 0 if
 194  * successful, otherwise a positive errno value.
 195  *
 196  * Some kinds of datapaths might not be practically enumerable.  This is not
 197  * considered an error. */
 198 int
 199 dp_enumerate_names(const char *type, struct sset *names)
 200 {
 201     const struct registered_dpif_class *registered_class;
 202     const struct dpif_class *dpif_class;
 203     int error;
 204
 205     dp_initialize();
 206     sset_clear(names);
 207
 208     registered_class = shash_find_data(&dpif_classes, type);
 209     if (!registered_class) {
 210         VLOG_WARN("could not enumerate unknown type: %s", type);
 211         return EAFNOSUPPORT;
 212     }
 213
 214     dpif_class = registered_class->dpif_class;
 215     error = dpif_class->enumerate ? dpif_class->enumerate(names) : 0;
 216
 217     if (error) {
 218         VLOG_WARN("failed to enumerate %s datapaths: %s", dpif_class->type,
 219                    strerror(error));
 220     }
 221
 222     return error;
 223 }
 224
 225 /* Parses 'datapath_name_', which is of the form [type@]name into its
 226  * component pieces.  'name' and 'type' must be freed by the caller.
 227  *
 228  * The returned 'type' is normalized, as if by dpif_normalize_type(). */
 229 void
 230 dp_parse_name(const char *datapath_name_, char **name, char **type)
 231 {
 232     char *datapath_name = xstrdup(datapath_name_);
 233     char *separator;
 234
 235     separator = strchr(datapath_name, '@');
 236     if (separator) {
 237         *separator = '\0';
 238         *type = datapath_name;
 239         *name = xstrdup(dpif_normalize_type(separator + 1));
 240     } else {
 241         *name = datapath_name;
 242         *type = xstrdup(dpif_normalize_type(NULL));
 243     }
 244 }
 245
 246 static int
 247 do_open(const char *name, const char *type, bool create, struct dpif **dpifp)
 248 {
 249     struct dpif *dpif = NULL;
 250     int error;
 251     struct registered_dpif_class *registered_class;
 252
 253     dp_initialize();
 254
 255     type = dpif_normalize_type(type);
 256
 257     registered_class = shash_find_data(&dpif_classes, type);
 258     if (!registered_class) {
 259         VLOG_WARN("could not create datapath %s of unknown type %s", name,
 260                   type);
 261         error = EAFNOSUPPORT;
 262         goto exit;
 263     }
 264
 265     error = registered_class->dpif_class->open(registered_class->dpif_class,
 266                                                name, create, &dpif);
 267     if (!error) {
 268         assert(dpif->dpif_class == registered_class->dpif_class);
 269         registered_class->refcount++;
 270     }
 271
 272 exit:
 273     *dpifp = error ? NULL : dpif;
 274     return error;
 275 }
 276
 277 /* Tries to open an existing datapath named 'name' and type 'type'.  Will fail
 278  * if no datapath with 'name' and 'type' exists.  'type' may be either NULL or
 279  * the empty string to specify the default system type.  Returns 0 if
 280  * successful, otherwise a positive errno value.  On success stores a pointer
 281  * to the datapath in '*dpifp', otherwise a null pointer. */
 282 int
 283 dpif_open(const char *name, const char *type, struct dpif **dpifp)
 284 {
 285     return do_open(name, type, false, dpifp);
 286 }
 287
 288 /* Tries to create and open a new datapath with the given 'name' and 'type'.
 289  * 'type' may be either NULL or the empty string to specify the default system
 290  * type.  Will fail if a datapath with 'name' and 'type' already exists.
 291  * Returns 0 if successful, otherwise a positive errno value.  On success
 292  * stores a pointer to the datapath in '*dpifp', otherwise a null pointer. */
 293 int
 294 dpif_create(const char *name, const char *type, struct dpif **dpifp)
 295 {
 296     return do_open(name, type, true, dpifp);
 297 }
 298
 299 /* Tries to open a datapath with the given 'name' and 'type', creating it if it
 300  * does not exist.  'type' may be either NULL or the empty string to specify
 301  * the default system type.  Returns 0 if successful, otherwise a positive
 302  * errno value. On success stores a pointer to the datapath in '*dpifp',
 303  * otherwise a null pointer. */
 304 int
 305 dpif_create_and_open(const char *name, const char *type, struct dpif **dpifp)
 306 {
 307     int error;
 308
 309     error = dpif_create(name, type, dpifp);
 310     if (error == EEXIST || error == EBUSY) {
 311         error = dpif_open(name, type, dpifp);
 312         if (error) {
 313             VLOG_WARN("datapath %s already exists but cannot be opened: %s",
 314                       name, strerror(error));
 315         }
 316     } else if (error) {
 317         VLOG_WARN("failed to create datapath %s: %s", name, strerror(error));
 318     }
 319     return error;
 320 }
 321
 322 /* Closes and frees the connection to 'dpif'.  Does not destroy the datapath
 323  * itself; call dpif_delete() first, instead, if that is desirable. */
 324 void
 325 dpif_close(struct dpif *dpif)
 326 {
 327     if (dpif) {
 328         struct registered_dpif_class *registered_class;
 329
 330         registered_class = shash_find_data(&dpif_classes,
 331                 dpif->dpif_class->type);
 332         assert(registered_class);
 333         assert(registered_class->refcount);
 334
 335         registered_class->refcount--;
 336         dpif_uninit(dpif, true);
 337     }
 338 }
 339
 340 /* Performs periodic work needed by 'dpif'. */
 341 void
 342 dpif_run(struct dpif *dpif)
 343 {
 344     if (dpif->dpif_class->run) {
 345         dpif->dpif_class->run(dpif);
 346     }
 347 }
 348
 349 /* Arranges for poll_block() to wake up when dp_run() needs to be called for
 350  * 'dpif'. */
 351 void
 352 dpif_wait(struct dpif *dpif)
 353 {
 354     if (dpif->dpif_class->wait) {
 355         dpif->dpif_class->wait(dpif);
 356     }
 357 }
 358
 359 /* Returns the name of datapath 'dpif' prefixed with the type
 360  * (for use in log messages). */
 361 const char *
 362 dpif_name(const struct dpif *dpif)
 363 {
 364     return dpif->full_name;
 365 }
 366
 367 /* Returns the name of datapath 'dpif' without the type
 368  * (for use in device names). */
 369 const char *
 370 dpif_base_name(const struct dpif *dpif)
 371 {
 372     return dpif->base_name;
 373 }
 374
 375 /* Returns the fully spelled out name for the given datapath 'type'.
 376  *
 377  * Normalized type string can be compared with strcmp().  Unnormalized type
 378  * string might be the same even if they have different spellings. */
 379 const char *
 380 dpif_normalize_type(const char *type)
 381 {
 382     return type && type[0] ? type : "system";
 383 }
 384
 385 /* Destroys the datapath that 'dpif' is connected to, first removing all of its
 386  * ports.  After calling this function, it does not make sense to pass 'dpif'
 387  * to any functions other than dpif_name() or dpif_close(). */
 388 int
 389 dpif_delete(struct dpif *dpif)
 390 {
 391     int error;
 392
 393     COVERAGE_INC(dpif_destroy);
 394
 395     error = dpif->dpif_class->destroy(dpif);
 396     log_operation(dpif, "delete", error);
 397     return error;
 398 }
 399
 400 /* Retrieves statistics for 'dpif' into 'stats'.  Returns 0 if successful,
 401  * otherwise a positive errno value. */
 402 int
 403 dpif_get_dp_stats(const struct dpif *dpif, struct dpif_dp_stats *stats)
 404 {
 405     int error = dpif->dpif_class->get_stats(dpif, stats);
 406     if (error) {
 407         memset(stats, 0, sizeof *stats);
 408     }
 409     log_operation(dpif, "get_stats", error);
 410     return error;
 411 }
 412
 413 /* Attempts to add 'netdev' as a port on 'dpif'.  If successful, returns 0 and
 414  * sets '*port_nop' to the new port's port number (if 'port_nop' is non-null).
 415  * On failure, returns a positive errno value and sets '*port_nop' to
 416  * UINT16_MAX (if 'port_nop' is non-null). */
 417 int
 418 dpif_port_add(struct dpif *dpif, struct netdev *netdev, uint16_t *port_nop)
 419 {
 420     const char *netdev_name = netdev_get_name(netdev);
 421     uint16_t port_no;
 422     int error;
 423
 424     COVERAGE_INC(dpif_port_add);
 425
 426     error = dpif->dpif_class->port_add(dpif, netdev, &port_no);
 427     if (!error) {
 428         VLOG_DBG_RL(&dpmsg_rl, "%s: added %s as port %"PRIu16,
 429                     dpif_name(dpif), netdev_name, port_no);
 430     } else {
 431         VLOG_WARN_RL(&error_rl, "%s: failed to add %s as port: %s",
 432                      dpif_name(dpif), netdev_name, strerror(error));
 433         port_no = UINT16_MAX;
 434     }
 435     if (port_nop) {
 436         *port_nop = port_no;
 437     }
 438     return error;
 439 }
 440
 441 /* Attempts to remove 'dpif''s port number 'port_no'.  Returns 0 if successful,
 442  * otherwise a positive errno value. */
 443 int
 444 dpif_port_del(struct dpif *dpif, uint16_t port_no)
 445 {
 446     int error;
 447
 448     COVERAGE_INC(dpif_port_del);
 449
 450     error = dpif->dpif_class->port_del(dpif, port_no);
 451     if (!error) {
 452         VLOG_DBG_RL(&dpmsg_rl, "%s: port_del(%"PRIu16")",
 453                     dpif_name(dpif), port_no);
 454     } else {
 455         log_operation(dpif, "port_del", error);
 456     }
 457     return error;
 458 }
 459
 460 /* Makes a deep copy of 'src' into 'dst'. */
 461 void
 462 dpif_port_clone(struct dpif_port *dst, const struct dpif_port *src)
 463 {
 464     dst->name = xstrdup(src->name);
 465     dst->type = xstrdup(src->type);
 466     dst->port_no = src->port_no;
 467 }
 468
 469 /* Frees memory allocated to members of 'dpif_port'.
 470  *
 471  * Do not call this function on a dpif_port obtained from
 472  * dpif_port_dump_next(): that function retains ownership of the data in the
 473  * dpif_port. */
 474 void
 475 dpif_port_destroy(struct dpif_port *dpif_port)
 476 {
 477     free(dpif_port->name);
 478     free(dpif_port->type);
 479 }
 480
 481 /* Looks up port number 'port_no' in 'dpif'.  On success, returns 0 and
 482  * initializes '*port' appropriately; on failure, returns a positive errno
 483  * value.
 484  *
 485  * The caller owns the data in 'port' and must free it with
 486  * dpif_port_destroy() when it is no longer needed. */
 487 int
 488 dpif_port_query_by_number(const struct dpif *dpif, uint16_t port_no,
 489                           struct dpif_port *port)
 490 {
 491     int error = dpif->dpif_class->port_query_by_number(dpif, port_no, port);
 492     if (!error) {
 493         VLOG_DBG_RL(&dpmsg_rl, "%s: port %"PRIu16" is device %s",
 494                     dpif_name(dpif), port_no, port->name);
 495     } else {
 496         memset(port, 0, sizeof *port);
 497         VLOG_WARN_RL(&error_rl, "%s: failed to query port %"PRIu16": %s",
 498                      dpif_name(dpif), port_no, strerror(error));
 499     }
 500     return error;
 501 }
 502
 503 /* Looks up port named 'devname' in 'dpif'.  On success, returns 0 and
 504  * initializes '*port' appropriately; on failure, returns a positive errno
 505  * value.
 506  *
 507  * The caller owns the data in 'port' and must free it with
 508  * dpif_port_destroy() when it is no longer needed. */
 509 int
 510 dpif_port_query_by_name(const struct dpif *dpif, const char *devname,
 511                         struct dpif_port *port)
 512 {
 513     int error = dpif->dpif_class->port_query_by_name(dpif, devname, port);
 514     if (!error) {
 515         VLOG_DBG_RL(&dpmsg_rl, "%s: device %s is on port %"PRIu16,
 516                     dpif_name(dpif), devname, port->port_no);
 517     } else {
 518         memset(port, 0, sizeof *port);
 519
 520         /* For ENOENT or ENODEV we use DBG level because the caller is probably
 521          * interested in whether 'dpif' actually has a port 'devname', so that
 522          * it's not an issue worth logging if it doesn't.  Other errors are
 523          * uncommon and more likely to indicate a real problem. */
 524         VLOG_RL(&error_rl,
 525                 error == ENOENT || error == ENODEV ? VLL_DBG : VLL_WARN,
 526                 "%s: failed to query port %s: %s",
 527                 dpif_name(dpif), devname, strerror(error));
 528     }
 529     return error;
 530 }
 531
 532 /* Returns one greater than the maximum port number accepted in flow
 533  * actions. */
 534 int
 535 dpif_get_max_ports(const struct dpif *dpif)
 536 {
 537     return dpif->dpif_class->get_max_ports(dpif);
 538 }
 539
 540 /* Returns the Netlink PID value to supply in OVS_ACTION_ATTR_USERSPACE actions
 541  * as the OVS_USERSPACE_ATTR_PID attribute's value, for use in flows whose
 542  * packets arrived on port 'port_no'.
 543  *
 544  * The return value is only meaningful when DPIF_UC_ACTION has been enabled in
 545  * the 'dpif''s listen mask.  It is allowed to change when DPIF_UC_ACTION is
 546  * disabled and then re-enabled, so a client that does that must be prepared to
 547  * update all of the flows that it installed that contain
 548  * OVS_ACTION_ATTR_USERSPACE actions. */
 549 uint32_t
 550 dpif_port_get_pid(const struct dpif *dpif, uint16_t port_no)
 551 {
 552     return (dpif->dpif_class->port_get_pid
 553             ? (dpif->dpif_class->port_get_pid)(dpif, port_no)
 554             : 0);
 555 }
 556
 557 /* Looks up port number 'port_no' in 'dpif'.  On success, returns 0 and copies
 558  * the port's name into the 'name_size' bytes in 'name', ensuring that the
 559  * result is null-terminated.  On failure, returns a positive errno value and
 560  * makes 'name' the empty string. */
 561 int
 562 dpif_port_get_name(struct dpif *dpif, uint16_t port_no,
 563                    char *name, size_t name_size)
 564 {
 565     struct dpif_port port;
 566     int error;
 567
 568     assert(name_size > 0);
 569
 570     error = dpif_port_query_by_number(dpif, port_no, &port);
 571     if (!error) {
 572         ovs_strlcpy(name, port.name, name_size);
 573         dpif_port_destroy(&port);
 574     } else {
 575         *name = '\0';
 576     }
 577     return error;
 578 }
 579
 580 /* Initializes 'dump' to begin dumping the ports in a dpif.
 581  *
 582  * This function provides no status indication.  An error status for the entire
 583  * dump operation is provided when it is completed by calling
 584  * dpif_port_dump_done().
 585  */
 586 void
 587 dpif_port_dump_start(struct dpif_port_dump *dump, const struct dpif *dpif)
 588 {
 589     dump->dpif = dpif;
 590     dump->error = dpif->dpif_class->port_dump_start(dpif, &dump->state);
 591     log_operation(dpif, "port_dump_start", dump->error);
 592 }
 593
 594 /* Attempts to retrieve another port from 'dump', which must have been
 595  * initialized with dpif_port_dump_start().  On success, stores a new dpif_port
 596  * into 'port' and returns true.  On failure, returns false.
 597  *
 598  * Failure might indicate an actual error or merely that the last port has been
 599  * dumped.  An error status for the entire dump operation is provided when it
 600  * is completed by calling dpif_port_dump_done().
 601  *
 602  * The dpif owns the data stored in 'port'.  It will remain valid until at
 603  * least the next time 'dump' is passed to dpif_port_dump_next() or
 604  * dpif_port_dump_done(). */
 605 bool
 606 dpif_port_dump_next(struct dpif_port_dump *dump, struct dpif_port *port)
 607 {
 608     const struct dpif *dpif = dump->dpif;
 609
 610     if (dump->error) {
 611         return false;
 612     }
 613
 614     dump->error = dpif->dpif_class->port_dump_next(dpif, dump->state, port);
 615     if (dump->error == EOF) {
 616         VLOG_DBG_RL(&dpmsg_rl, "%s: dumped all ports", dpif_name(dpif));
 617     } else {
 618         log_operation(dpif, "port_dump_next", dump->error);
 619     }
 620
 621     if (dump->error) {
 622         dpif->dpif_class->port_dump_done(dpif, dump->state);
 623         return false;
 624     }
 625     return true;
 626 }
 627
 628 /* Completes port table dump operation 'dump', which must have been initialized
 629  * with dpif_port_dump_start().  Returns 0 if the dump operation was
 630  * error-free, otherwise a positive errno value describing the problem. */
 631 int
 632 dpif_port_dump_done(struct dpif_port_dump *dump)
 633 {
 634     const struct dpif *dpif = dump->dpif;
 635     if (!dump->error) {
 636         dump->error = dpif->dpif_class->port_dump_done(dpif, dump->state);
 637         log_operation(dpif, "port_dump_done", dump->error);
 638     }
 639     return dump->error == EOF ? 0 : dump->error;
 640 }
 641
 642 /* Polls for changes in the set of ports in 'dpif'.  If the set of ports in
 643  * 'dpif' has changed, this function does one of the following:
 644  *
 645  * - Stores the name of the device that was added to or deleted from 'dpif' in
 646  *   '*devnamep' and returns 0.  The caller is responsible for freeing
 647  *   '*devnamep' (with free()) when it no longer needs it.
 648  *
 649  * - Returns ENOBUFS and sets '*devnamep' to NULL.
 650  *
 651  * This function may also return 'false positives', where it returns 0 and
 652  * '*devnamep' names a device that was not actually added or deleted or it
 653  * returns ENOBUFS without any change.
 654  *
 655  * Returns EAGAIN if the set of ports in 'dpif' has not changed.  May also
 656  * return other positive errno values to indicate that something has gone
 657  * wrong. */
 658 int
 659 dpif_port_poll(const struct dpif *dpif, char **devnamep)
 660 {
 661     int error = dpif->dpif_class->port_poll(dpif, devnamep);
 662     if (error) {
 663         *devnamep = NULL;
 664     }
 665     return error;
 666 }
 667
 668 /* Arranges for the poll loop to wake up when port_poll(dpif) will return a
 669  * value other than EAGAIN. */
 670 void
 671 dpif_port_poll_wait(const struct dpif *dpif)
 672 {
 673     dpif->dpif_class->port_poll_wait(dpif);
 674 }
 675
 676 /* Extracts the flow stats for a packet.  The 'flow' and 'packet'
 677  * arguments must have been initialized through a call to flow_extract().
 678  */
 679 void
 680 dpif_flow_stats_extract(const struct flow *flow, const struct ofpbuf *packet,
 681                         struct dpif_flow_stats *stats)
 682 {
 683     stats->tcp_flags = packet_get_tcp_flags(packet, flow);
 684     stats->n_bytes = packet->size;
 685     stats->n_packets = 1;
 686     stats->used = time_msec();
 687 }
 688
 689 /* Appends a human-readable representation of 'stats' to 's'. */
 690 void
 691 dpif_flow_stats_format(const struct dpif_flow_stats *stats, struct ds *s)
 692 {
 693     ds_put_format(s, "packets:%"PRIu64", bytes:%"PRIu64", used:",
 694                   stats->n_packets, stats->n_bytes);
 695     if (stats->used) {
 696         ds_put_format(s, "%.3fs", (time_msec() - stats->used) / 1000.0);
 697     } else {
 698         ds_put_format(s, "never");
 699     }
 700     /* XXX tcp_flags? */
 701 }
 702
 703 /* Deletes all flows from 'dpif'.  Returns 0 if successful, otherwise a
 704  * positive errno value.  */
 705 int
 706 dpif_flow_flush(struct dpif *dpif)
 707 {
 708     int error;
 709
 710     COVERAGE_INC(dpif_flow_flush);
 711
 712     error = dpif->dpif_class->flow_flush(dpif);
 713     log_operation(dpif, "flow_flush", error);
 714     return error;
 715 }
 716
 717 /* Queries 'dpif' for a flow entry.  The flow is specified by the Netlink
 718  * attributes with types OVS_KEY_ATTR_* in the 'key_len' bytes starting at
 719  * 'key'.
 720  *
 721  * Returns 0 if successful.  If no flow matches, returns ENOENT.  On other
 722  * failure, returns a positive errno value.
 723  *
 724  * If 'actionsp' is nonnull, then on success '*actionsp' will be set to an
 725  * ofpbuf owned by the caller that contains the Netlink attributes for the
 726  * flow's actions.  The caller must free the ofpbuf (with ofpbuf_delete()) when
 727  * it is no longer needed.
 728  *
 729  * If 'stats' is nonnull, then on success it will be updated with the flow's
 730  * statistics. */
 731 int
 732 dpif_flow_get(const struct dpif *dpif,
 733               const struct nlattr *key, size_t key_len,
 734               struct ofpbuf **actionsp, struct dpif_flow_stats *stats)
 735 {
 736     int error;
 737
 738     COVERAGE_INC(dpif_flow_get);
 739
 740     error = dpif->dpif_class->flow_get(dpif, key, key_len, actionsp, stats);
 741     if (error) {
 742         if (actionsp) {
 743             *actionsp = NULL;
 744         }
 745         if (stats) {
 746             memset(stats, 0, sizeof *stats);
 747         }
 748     }
 749     if (should_log_flow_message(error)) {
 750         const struct nlattr *actions;
 751         size_t actions_len;
 752
 753         if (!error && actionsp) {
 754             actions = (*actionsp)->data;
 755             actions_len = (*actionsp)->size;
 756         } else {
 757             actions = NULL;
 758             actions_len = 0;
 759         }
 760         log_flow_message(dpif, error, "flow_get", key, key_len, stats,
 761                          actions, actions_len);
 762     }
 763     return error;
 764 }
 765
 766 static int
 767 dpif_flow_put__(struct dpif *dpif, const struct dpif_flow_put *put)
 768 {
 769     int error;
 770
 771     COVERAGE_INC(dpif_flow_put);
 772     assert(!(put->flags & ~(DPIF_FP_CREATE | DPIF_FP_MODIFY
 773                             | DPIF_FP_ZERO_STATS)));
 774
 775     error = dpif->dpif_class->flow_put(dpif, put);
 776     if (error && put->stats) {
 777         memset(put->stats, 0, sizeof *put->stats);
 778     }
 779     log_flow_put_message(dpif, put, error);
 780     return error;
 781 }
 782
 783 /* Adds or modifies a flow in 'dpif'.  The flow is specified by the Netlink
 784  * attributes with types OVS_KEY_ATTR_* in the 'key_len' bytes starting at
 785  * 'key'.  The associated actions are specified by the Netlink attributes with
 786  * types OVS_ACTION_ATTR_* in the 'actions_len' bytes starting at 'actions'.
 787  *
 788  * - If the flow's key does not exist in 'dpif', then the flow will be added if
 789  *   'flags' includes DPIF_FP_CREATE.  Otherwise the operation will fail with
 790  *   ENOENT.
 791  *
 792  *   If the operation succeeds, then 'stats', if nonnull, will be zeroed.
 793  *
 794  * - If the flow's key does exist in 'dpif', then the flow's actions will be
 795  *   updated if 'flags' includes DPIF_FP_MODIFY.  Otherwise the operation will
 796  *   fail with EEXIST.  If the flow's actions are updated, then its statistics
 797  *   will be zeroed if 'flags' includes DPIF_FP_ZERO_STATS, and left as-is
 798  *   otherwise.
 799  *
 800  *   If the operation succeeds, then 'stats', if nonnull, will be set to the
 801  *   flow's statistics before the update.
 802  */
 803 int
 804 dpif_flow_put(struct dpif *dpif, enum dpif_flow_put_flags flags,
 805               const struct nlattr *key, size_t key_len,
 806               const struct nlattr *actions, size_t actions_len,
 807               struct dpif_flow_stats *stats)
 808 {
 809     struct dpif_flow_put put;
 810
 811     put.flags = flags;
 812     put.key = key;
 813     put.key_len = key_len;
 814     put.actions = actions;
 815     put.actions_len = actions_len;
 816     put.stats = stats;
 817     return dpif_flow_put__(dpif, &put);
 818 }
 819
 820 static int
 821 dpif_flow_del__(struct dpif *dpif, struct dpif_flow_del *del)
 822 {
 823     int error;
 824
 825     COVERAGE_INC(dpif_flow_del);
 826
 827     error = dpif->dpif_class->flow_del(dpif, del);
 828     if (error && del->stats) {
 829         memset(del->stats, 0, sizeof *del->stats);
 830     }
 831     log_flow_del_message(dpif, del, error);
 832     return error;
 833 }
 834
 835 /* Deletes a flow from 'dpif' and returns 0, or returns ENOENT if 'dpif' does
 836  * not contain such a flow.  The flow is specified by the Netlink attributes
 837  * with types OVS_KEY_ATTR_* in the 'key_len' bytes starting at 'key'.
 838  *
 839  * If the operation succeeds, then 'stats', if nonnull, will be set to the
 840  * flow's statistics before its deletion. */
 841 int
 842 dpif_flow_del(struct dpif *dpif,
 843               const struct nlattr *key, size_t key_len,
 844               struct dpif_flow_stats *stats)
 845 {
 846     struct dpif_flow_del del;
 847
 848     del.key = key;
 849     del.key_len = key_len;
 850     del.stats = stats;
 851     return dpif_flow_del__(dpif, &del);
 852 }
 853
 854 /* Initializes 'dump' to begin dumping the flows in a dpif.
 855  *
 856  * This function provides no status indication.  An error status for the entire
 857  * dump operation is provided when it is completed by calling
 858  * dpif_flow_dump_done().
 859  */
 860 void
 861 dpif_flow_dump_start(struct dpif_flow_dump *dump, const struct dpif *dpif)
 862 {
 863     dump->dpif = dpif;
 864     dump->error = dpif->dpif_class->flow_dump_start(dpif, &dump->state);
 865     log_operation(dpif, "flow_dump_start", dump->error);
 866 }
 867
 868 /* Attempts to retrieve another flow from 'dump', which must have been
 869  * initialized with dpif_flow_dump_start().  On success, updates the output
 870  * parameters as described below and returns true.  Otherwise, returns false.
 871  * Failure might indicate an actual error or merely the end of the flow table.
 872  * An error status for the entire dump operation is provided when it is
 873  * completed by calling dpif_flow_dump_done().
 874  *
 875  * On success, if 'key' and 'key_len' are nonnull then '*key' and '*key_len'
 876  * will be set to Netlink attributes with types OVS_KEY_ATTR_* representing the
 877  * dumped flow's key.  If 'actions' and 'actions_len' are nonnull then they are
 878  * set to Netlink attributes with types OVS_ACTION_ATTR_* representing the
 879  * dumped flow's actions.  If 'stats' is nonnull then it will be set to the
 880  * dumped flow's statistics.
 881  *
 882  * All of the returned data is owned by 'dpif', not by the caller, and the
 883  * caller must not modify or free it.  'dpif' guarantees that it remains
 884  * accessible and unchanging until at least the next call to 'flow_dump_next'
 885  * or 'flow_dump_done' for 'dump'. */
 886 bool
 887 dpif_flow_dump_next(struct dpif_flow_dump *dump,
 888                     const struct nlattr **key, size_t *key_len,
 889                     const struct nlattr **actions, size_t *actions_len,
 890                     const struct dpif_flow_stats **stats)
 891 {
 892     const struct dpif *dpif = dump->dpif;
 893     int error = dump->error;
 894
 895     if (!error) {
 896         error = dpif->dpif_class->flow_dump_next(dpif, dump->state,
 897                                                  key, key_len,
 898                                                  actions, actions_len,
 899                                                  stats);
 900         if (error) {
 901             dpif->dpif_class->flow_dump_done(dpif, dump->state);
 902         }
 903     }
 904     if (error) {
 905         if (key) {
 906             *key = NULL;
 907             *key_len = 0;
 908         }
 909         if (actions) {
 910             *actions = NULL;
 911             *actions_len = 0;
 912         }
 913         if (stats) {
 914             *stats = NULL;
 915         }
 916     }
 917     if (!dump->error) {
 918         if (error == EOF) {
 919             VLOG_DBG_RL(&dpmsg_rl, "%s: dumped all flows", dpif_name(dpif));
 920         } else if (should_log_flow_message(error)) {
 921             log_flow_message(dpif, error, "flow_dump",
 922                              key ? *key : NULL, key ? *key_len : 0,
 923                              stats ? *stats : NULL, actions ? *actions : NULL,
 924                              actions ? *actions_len : 0);
 925         }
 926     }
 927     dump->error = error;
 928     return !error;
 929 }
 930
 931 /* Completes flow table dump operation 'dump', which must have been initialized
 932  * with dpif_flow_dump_start().  Returns 0 if the dump operation was
 933  * error-free, otherwise a positive errno value describing the problem. */
 934 int
 935 dpif_flow_dump_done(struct dpif_flow_dump *dump)
 936 {
 937     const struct dpif *dpif = dump->dpif;
 938     if (!dump->error) {
 939         dump->error = dpif->dpif_class->flow_dump_done(dpif, dump->state);
 940         log_operation(dpif, "flow_dump_done", dump->error);
 941     }
 942     return dump->error == EOF ? 0 : dump->error;
 943 }
 944
 945 static int
 946 dpif_execute__(struct dpif *dpif, const struct dpif_execute *execute)
 947 {
 948     int error;
 949
 950     COVERAGE_INC(dpif_execute);
 951     if (execute->actions_len > 0) {
 952         error = dpif->dpif_class->execute(dpif, execute);
 953     } else {
 954         error = 0;
 955     }
 956
 957     log_execute_message(dpif, execute, error);
 958
 959     return error;
 960 }
 961
 962 /* Causes 'dpif' to perform the 'actions_len' bytes of actions in 'actions' on
 963  * the Ethernet frame specified in 'packet' taken from the flow specified in
 964  * the 'key_len' bytes of 'key'.  ('key' is mostly redundant with 'packet', but
 965  * it contains some metadata that cannot be recovered from 'packet', such as
 966  * tun_id and in_port.)
 967  *
 968  * Returns 0 if successful, otherwise a positive errno value. */
 969 int
 970 dpif_execute(struct dpif *dpif,
 971              const struct nlattr *key, size_t key_len,
 972              const struct nlattr *actions, size_t actions_len,
 973              const struct ofpbuf *buf)
 974 {
 975     struct dpif_execute execute;
 976
 977     execute.key = key;
 978     execute.key_len = key_len;
 979     execute.actions = actions;
 980     execute.actions_len = actions_len;
 981     execute.packet = buf;
 982     return dpif_execute__(dpif, &execute);
 983 }
 984
 985 /* Executes each of the 'n_ops' operations in 'ops' on 'dpif', in the order in
 986  * which they are specified, placing each operation's results in the "output"
 987  * members documented in comments.
 988  *
 989  * This function exists because some datapaths can perform batched operations
 990  * faster than individual operations. */
 991 void
 992 dpif_operate(struct dpif *dpif, struct dpif_op **ops, size_t n_ops)
 993 {
 994     size_t i;
 995
 996     if (dpif->dpif_class->operate) {
 997         dpif->dpif_class->operate(dpif, ops, n_ops);
 998
 999         for (i = 0; i < n_ops; i++) {
1000             struct dpif_op *op = ops[i];
1001
1002             switch (op->type) {
1003             case DPIF_OP_FLOW_PUT:
1004                 log_flow_put_message(dpif, &op->u.flow_put, op->error);
1005                 break;
1006
1007             case DPIF_OP_FLOW_DEL:
1008                 log_flow_del_message(dpif, &op->u.flow_del, op->error);
1009                 break;
1010
1011             case DPIF_OP_EXECUTE:
1012                 log_execute_message(dpif, &op->u.execute, op->error);
1013                 break;
1014             }
1015         }
1016         return;
1017     }
1018
1019     for (i = 0; i < n_ops; i++) {
1020         struct dpif_op *op = ops[i];
1021
1022         switch (op->type) {
1023         case DPIF_OP_FLOW_PUT:
1024             op->error = dpif_flow_put__(dpif, &op->u.flow_put);
1025             break;
1026
1027         case DPIF_OP_FLOW_DEL:
1028             op->error = dpif_flow_del__(dpif, &op->u.flow_del);
1029             break;
1030
1031         case DPIF_OP_EXECUTE:
1032             op->error = dpif_execute__(dpif, &op->u.execute);
1033             break;
1034
1035         default:
1036             NOT_REACHED();
1037         }
1038     }
1039 }
1040
1041
1042 /* Returns a string that represents 'type', for use in log messages. */
1043 const char *
1044 dpif_upcall_type_to_string(enum dpif_upcall_type type)
1045 {
1046     switch (type) {
1047     case DPIF_UC_MISS: return "miss";
1048     case DPIF_UC_ACTION: return "action";
1049     case DPIF_N_UC_TYPES: default: return "<unknown>";
1050     }
1051 }
1052
1053 /* Enables or disables receiving packets with dpif_recv() on 'dpif'.  Returns 0
1054  * if successful, otherwise a positive errno value.
1055  *
1056  * Turning packet receive off and then back on may change the Netlink PID
1057  * assignments returned by dpif_port_get_pid().  If the client does this, it
1058  * must update all of the flows that have OVS_ACTION_ATTR_USERSPACE actions
1059  * using the new PID assignment. */
1060 int
1061 dpif_recv_set(struct dpif *dpif, bool enable)
1062 {
1063     int error = dpif->dpif_class->recv_set(dpif, enable);
1064     log_operation(dpif, "recv_set", error);
1065     return error;
1066 }
1067
1068 /* Polls for an upcall from 'dpif'.  If successful, stores the upcall into
1069  * '*upcall'.  Should only be called if dpif_recv_set() has been used to enable
1070  * receiving packets on 'dpif'.
1071  *
1072  * The caller takes ownership of the data that 'upcall' points to.
1073  * 'upcall->key' and 'upcall->actions' (if nonnull) point into data owned by
1074  * 'upcall->packet', so their memory cannot be freed separately.  (This is
1075  * hardly a great way to do things but it works out OK for the dpif providers
1076  * and clients that exist so far.)
1077  *
1078  * Returns 0 if successful, otherwise a positive errno value.  Returns EAGAIN
1079  * if no upcall is immediately available. */
1080 int
1081 dpif_recv(struct dpif *dpif, struct dpif_upcall *upcall)
1082 {
1083     int error = dpif->dpif_class->recv(dpif, upcall);
1084     if (!error && !VLOG_DROP_DBG(&dpmsg_rl)) {
1085         struct ds flow;
1086         char *packet;
1087
1088         packet = ofp_packet_to_string(upcall->packet->data,
1089                                       upcall->packet->size);
1090
1091         ds_init(&flow);
1092         odp_flow_key_format(upcall->key, upcall->key_len, &flow);
1093
1094         VLOG_DBG("%s: %s upcall:\n%s\n%s",
1095                  dpif_name(dpif), dpif_upcall_type_to_string(upcall->type),
1096                  ds_cstr(&flow), packet);
1097
1098         ds_destroy(&flow);
1099         free(packet);
1100     } else if (error && error != EAGAIN) {
1101         log_operation(dpif, "recv", error);
1102     }
1103     return error;
1104 }
1105
1106 /* Discards all messages that would otherwise be received by dpif_recv() on
1107  * 'dpif'. */
1108 void
1109 dpif_recv_purge(struct dpif *dpif)
1110 {
1111     COVERAGE_INC(dpif_purge);
1112     if (dpif->dpif_class->recv_purge) {
1113         dpif->dpif_class->recv_purge(dpif);
1114     }
1115 }
1116
1117 /* Arranges for the poll loop to wake up when 'dpif' has a message queued to be
1118  * received with dpif_recv(). */
1119 void
1120 dpif_recv_wait(struct dpif *dpif)
1121 {
1122     dpif->dpif_class->recv_wait(dpif);
1123 }
1124
1125 /* Obtains the NetFlow engine type and engine ID for 'dpif' into '*engine_type'
1126  * and '*engine_id', respectively. */
1127 void
1128 dpif_get_netflow_ids(const struct dpif *dpif,
1129                      uint8_t *engine_type, uint8_t *engine_id)
1130 {
1131     *engine_type = dpif->netflow_engine_type;
1132     *engine_id = dpif->netflow_engine_id;
1133 }
1134
1135 /* Translates OpenFlow queue ID 'queue_id' (in host byte order) into a priority
1136  * value used for setting packet priority.
1137  * On success, returns 0 and stores the priority into '*priority'.
1138  * On failure, returns a positive errno value and stores 0 into '*priority'. */
1139 int
1140 dpif_queue_to_priority(const struct dpif *dpif, uint32_t queue_id,
1141                        uint32_t *priority)
1142 {
1143     int error = (dpif->dpif_class->queue_to_priority
1144                  ? dpif->dpif_class->queue_to_priority(dpif, queue_id,
1145                                                        priority)
1146                  : EOPNOTSUPP);
1147     if (error) {
1148         *priority = 0;
1149     }
1150     log_operation(dpif, "queue_to_priority", error);
1151     return error;
1152 }
1153 \f
1154 void
1155 dpif_init(struct dpif *dpif, const struct dpif_class *dpif_class,
1156           const char *name,
1157           uint8_t netflow_engine_type, uint8_t netflow_engine_id)
1158 {
1159     dpif->dpif_class = dpif_class;
1160     dpif->base_name = xstrdup(name);
1161     dpif->full_name = xasprintf("%s@%s", dpif_class->type, name);
1162     dpif->netflow_engine_type = netflow_engine_type;
1163     dpif->netflow_engine_id = netflow_engine_id;
1164 }
1165
1166 /* Undoes the results of initialization.
1167  *
1168  * Normally this function only needs to be called from dpif_close().
1169  * However, it may be called by providers due to an error on opening
1170  * that occurs after initialization.  It this case dpif_close() would
1171  * never be called. */
1172 void
1173 dpif_uninit(struct dpif *dpif, bool close)
1174 {
1175     char *base_name = dpif->base_name;
1176     char *full_name = dpif->full_name;
1177
1178     if (close) {
1179         dpif->dpif_class->close(dpif);
1180     }
1181
1182     free(base_name);
1183     free(full_name);
1184 }
1185 \f
1186 static void
1187 log_operation(const struct dpif *dpif, const char *operation, int error)
1188 {
1189     if (!error) {
1190         VLOG_DBG_RL(&dpmsg_rl, "%s: %s success", dpif_name(dpif), operation);
1191     } else if (ofperr_is_valid(error)) {
1192         VLOG_WARN_RL(&error_rl, "%s: %s failed (%s)",
1193                      dpif_name(dpif), operation, ofperr_get_name(error));
1194     } else {
1195         VLOG_WARN_RL(&error_rl, "%s: %s failed (%s)",
1196                      dpif_name(dpif), operation, strerror(error));
1197     }
1198 }
1199
1200 static enum vlog_level
1201 flow_message_log_level(int error)
1202 {
1203     return error ? VLL_WARN : VLL_DBG;
1204 }
1205
1206 static bool
1207 should_log_flow_message(int error)
1208 {
1209     return !vlog_should_drop(THIS_MODULE, flow_message_log_level(error),
1210                              error ? &error_rl : &dpmsg_rl);
1211 }
1212
1213 static void
1214 log_flow_message(const struct dpif *dpif, int error, const char *operation,
1215                  const struct nlattr *key, size_t key_len,
1216                  const struct dpif_flow_stats *stats,
1217                  const struct nlattr *actions, size_t actions_len)
1218 {
1219     struct ds ds = DS_EMPTY_INITIALIZER;
1220     ds_put_format(&ds, "%s: ", dpif_name(dpif));
1221     if (error) {
1222         ds_put_cstr(&ds, "failed to ");
1223     }
1224     ds_put_format(&ds, "%s ", operation);
1225     if (error) {
1226         ds_put_format(&ds, "(%s) ", strerror(error));
1227     }
1228     odp_flow_key_format(key, key_len, &ds);
1229     if (stats) {
1230         ds_put_cstr(&ds, ", ");
1231         dpif_flow_stats_format(stats, &ds);
1232     }
1233     if (actions || actions_len) {
1234         ds_put_cstr(&ds, ", actions:");
1235         format_odp_actions(&ds, actions, actions_len);
1236     }
1237     vlog(THIS_MODULE, flow_message_log_level(error), "%s", ds_cstr(&ds));
1238     ds_destroy(&ds);
1239 }
1240
1241 static void
1242 log_flow_put_message(struct dpif *dpif, const struct dpif_flow_put *put,
1243                      int error)
1244 {
1245     if (should_log_flow_message(error)) {
1246         struct ds s;
1247
1248         ds_init(&s);
1249         ds_put_cstr(&s, "put");
1250         if (put->flags & DPIF_FP_CREATE) {
1251             ds_put_cstr(&s, "[create]");
1252         }
1253         if (put->flags & DPIF_FP_MODIFY) {
1254             ds_put_cstr(&s, "[modify]");
1255         }
1256         if (put->flags & DPIF_FP_ZERO_STATS) {
1257             ds_put_cstr(&s, "[zero]");
1258         }
1259         log_flow_message(dpif, error, ds_cstr(&s),
1260                          put->key, put->key_len, put->stats,
1261                          put->actions, put->actions_len);
1262         ds_destroy(&s);
1263     }
1264 }
1265
1266 static void
1267 log_flow_del_message(struct dpif *dpif, const struct dpif_flow_del *del,
1268                      int error)
1269 {
1270     if (should_log_flow_message(error)) {
1271         log_flow_message(dpif, error, "flow_del", del->key, del->key_len,
1272                          !error ? del->stats : NULL, NULL, 0);
1273     }
1274 }
1275
1276 static void
1277 log_execute_message(struct dpif *dpif, const struct dpif_execute *execute,
1278                     int error)
1279 {
1280     if (!(error ? VLOG_DROP_WARN(&error_rl) : VLOG_DROP_DBG(&dpmsg_rl))) {
1281         struct ds ds = DS_EMPTY_INITIALIZER;
1282         char *packet;
1283
1284         packet = ofp_packet_to_string(execute->packet->data,
1285                                       execute->packet->size);
1286         ds_put_format(&ds, "%s: execute ", dpif_name(dpif));
1287         format_odp_actions(&ds, execute->actions, execute->actions_len);
1288         if (error) {
1289             ds_put_format(&ds, " failed (%s)", strerror(error));
1290         }
1291         ds_put_format(&ds, " on packet %s", packet);
1292         vlog(THIS_MODULE, error ? VLL_WARN : VLL_DBG, "%s", ds_cstr(&ds));
1293         ds_destroy(&ds);
1294         free(packet);
1295     }
1296 }