Clean up logging PAZ-942
[pazpar2-moved-to-github.git] / src / connection.c
1 /* This file is part of Pazpar2.
2    Copyright (C) Index Data
3
4 Pazpar2 is free software; you can redistribute it and/or modify it under
5 the terms of the GNU General Public License as published by the Free
6 Software Foundation; either version 2, or (at your option) any later
7 version.
8
9 Pazpar2 is distributed in the hope that it will be useful, but WITHOUT ANY
10 WARRANTY; without even the implied warranty of MERCHANTABILITY or
11 FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
12 for more details.
13
14 You should have received a copy of the GNU General Public License
15 along with this program; if not, write to the Free Software
16 Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA  02110-1301  USA
17
18 */
19
20 /** \file connection.c
21     \brief Z39.50 connection (low-level client)
22 */
23
24 #if HAVE_CONFIG_H
25 #include <config.h>
26 #endif
27
28 #include <stdlib.h>
29 #include <stdio.h>
30 #include <string.h>
31 #if HAVE_SYS_TIME_H
32 #include <sys/time.h>
33 #endif
34 #if HAVE_UNISTD_H
35 #include <unistd.h>
36 #endif
37
38 #include <signal.h>
39 #include <assert.h>
40
41 #include <yaz/log.h>
42 #include <yaz/comstack.h>
43 #include <yaz/tcpip.h>
44 #include "connection.h"
45 #include "session.h"
46 #include "host.h"
47 #include "client.h"
48 #include "settings.h"
49
50 /* connection counting (1) , disable connection counting (0) */
51 #if 1
52 static YAZ_MUTEX g_mutex = 0;
53 static int no_connections = 0;
54 static int total_no_connections = 0;
55
56 static int connection_use(int delta)
57 {
58     int result;
59     if (!g_mutex)
60         yaz_mutex_create(&g_mutex);
61     yaz_mutex_enter(g_mutex);
62     no_connections += delta;
63     result = no_connections;
64     if (delta > 0)
65         total_no_connections += delta;
66     yaz_mutex_leave(g_mutex);
67     if (delta == 0)
68             return result;
69     yaz_log(YLOG_LOG, "%s connections=%d", delta > 0 ? "INC" : "DEC",
70             no_connections);
71     return result;
72 }
73
74 int connections_count(void)
75 {
76     return connection_use(0);
77 }
78
79
80 #else
81 #define connection_use(x)
82 #define connections_count(x) 0
83 #define connections_count_total(x) 0
84 #endif
85
86
87 /** \brief Represents a physical, reusable  connection to a remote Z39.50 host
88  */
89 struct connection {
90     IOCHAN iochan;
91     ZOOM_connection link;
92     struct host *host;
93     struct client *client;
94     char *zproxy;
95     char *url;
96     enum {
97         Conn_Closed,
98         Conn_Connecting,
99         Conn_Open
100     } state;
101     int operation_timeout;
102     int session_timeout;
103     struct connection *next; // next for same host or next in free list
104 };
105
106 static int connection_connect(struct connection *con, iochan_man_t iochan_man);
107
108 static int connection_is_idle(struct connection *co)
109 {
110     ZOOM_connection link = co->link;
111     int event;
112
113     if (co->state != Conn_Open || !link)
114         return 0;
115
116     if (!ZOOM_connection_is_idle(link))
117         return 0;
118     event = ZOOM_connection_peek_event(link);
119     if (event == ZOOM_EVENT_NONE)
120         return 1;
121     else
122         return 0;
123 }
124
125 ZOOM_connection connection_get_link(struct connection *co)
126 {
127     return co->link;
128 }
129
130 static void remove_connection_from_host(struct connection *con)
131 {
132     struct connection **conp = &con->host->connections;
133     assert(con);
134     while (*conp)
135     {
136         if (*conp == con)
137         {
138             *conp = (*conp)->next;
139             break;
140         }
141         conp = &(*conp)->next;
142     }
143     yaz_cond_broadcast(con->host->cond_ready);
144 }
145
146 // Close connection and recycle structure
147 static void connection_destroy(struct connection *co)
148 {
149     if (co->link)
150     {
151         ZOOM_connection_destroy(co->link);
152         iochan_destroy(co->iochan);
153     }
154     yaz_log(YLOG_DEBUG, "%p Connection destroy %s", co, co->url);
155
156     if (co->client)
157     {
158         client_disconnect(co->client);
159     }
160
161     xfree(co->zproxy);
162     xfree(co->url);
163     xfree(co);
164     connection_use(-1);
165 }
166
167 // Creates a new connection for client, associated with the host of
168 // client's database
169 static struct connection *connection_create(struct client *cl,
170                                             const char *url,
171                                             struct host *host,
172                                             int operation_timeout,
173                                             int session_timeout,
174                                             iochan_man_t iochan_man)
175 {
176     struct connection *co;
177
178     co = xmalloc(sizeof(*co));
179     co->host = host;
180
181     co->client = cl;
182     co->url = xstrdup(url);
183     co->zproxy = 0;
184     client_set_connection(cl, co);
185     co->link = 0;
186     co->state = Conn_Closed;
187     co->operation_timeout = operation_timeout;
188     co->session_timeout = session_timeout;
189
190     if (host->ipport)
191         connection_connect(co, iochan_man);
192
193     yaz_mutex_enter(host->mutex);
194     co->next = co->host->connections;
195     co->host->connections = co;
196     yaz_mutex_leave(host->mutex);
197
198     connection_use(1);
199     return co;
200 }
201
202 static void non_block_events(struct connection *co)
203 {
204     int got_records = 0;
205     IOCHAN iochan = co->iochan;
206     ZOOM_connection link = co->link;
207     while (1)
208     {
209         struct client *cl = co->client;
210         int ev;
211         int r = ZOOM_event_nonblock(1, &link);
212         if (!r)
213             break;
214         if (!cl)
215             continue;
216         ev = ZOOM_connection_last_event(link);
217
218 #if 1
219         yaz_log(YLOG_DEBUG, "%p Connection ZOOM_EVENT_%s", co, ZOOM_get_event_str(ev));
220 #endif
221         switch (ev)
222         {
223         case ZOOM_EVENT_TIMEOUT:
224             break;
225         case ZOOM_EVENT_END:
226             {
227                 const char *error, *addinfo;
228                 int err;
229                 if ((err = ZOOM_connection_error(link, &error, &addinfo)))
230                 {
231                     struct session *se = client_get_session(cl);
232
233                     session_log(se, YLOG_WARN, "%s: Error %s (%s)",
234                                 client_get_id(cl), error, addinfo);
235                     client_set_diagnostic(cl, err, error, addinfo);
236                     client_set_state(cl, Client_Error);
237                 }
238                 else
239                 {
240                     iochan_settimeout(iochan, co->session_timeout);
241                     client_set_state(cl, Client_Idle);
242                 }
243                 yaz_cond_broadcast(co->host->cond_ready);
244             }
245             break;
246         case ZOOM_EVENT_SEND_DATA:
247             break;
248         case ZOOM_EVENT_RECV_DATA:
249             break;
250         case ZOOM_EVENT_UNKNOWN:
251             break;
252         case ZOOM_EVENT_SEND_APDU:
253             client_set_state(co->client, Client_Working);
254             iochan_settimeout(iochan, co->operation_timeout);
255             break;
256         case ZOOM_EVENT_RECV_APDU:
257             break;
258         case ZOOM_EVENT_CONNECT:
259             co->state = Conn_Open;
260             break;
261         case ZOOM_EVENT_RECV_SEARCH:
262             client_search_response(cl);
263             break;
264         case ZOOM_EVENT_RECV_RECORD:
265             client_record_response(cl, &got_records);
266             break;
267         default:
268             yaz_log(YLOG_LOG, "Unhandled event (%d) from %s",
269                     ev, client_get_id(cl));
270             break;
271         }
272     }
273     if (got_records)
274     {
275         struct client *cl = co->client;
276         if (cl)
277         {
278             client_check_preferred_watch(cl);
279             client_got_records(cl);
280         }
281     }
282 }
283
284 void connection_continue(struct connection *co)
285 {
286     int r = ZOOM_connection_exec_task(co->link);
287     if (!r)
288     {
289         struct client *cl = co->client;
290
291         client_lock(cl);
292         non_block_events(co);
293         client_unlock(cl);
294     }
295     else
296     {
297         iochan_setflags(co->iochan, ZOOM_connection_get_mask(co->link));
298         iochan_setfd(co->iochan, ZOOM_connection_get_socket(co->link));
299     }
300 }
301
302 static void connection_handler(IOCHAN iochan, int event)
303 {
304     struct connection *co = iochan_getdata(iochan);
305     struct client *cl;
306     struct host *host = co->host;
307
308     yaz_mutex_enter(host->mutex);
309     cl = co->client;
310     if (!cl)
311     {
312         /* no client associated with it.. We are probably getting
313            a closed connection from the target.. Or, perhaps, an unexpected
314            package.. We will just close the connection */
315         yaz_log(YLOG_LOG, "timeout connection %p event=%d", co, event);
316         remove_connection_from_host(co);
317         yaz_mutex_leave(host->mutex);
318         connection_destroy(co);
319     }
320     else if (event & EVENT_TIMEOUT)
321     {
322         ZOOM_connection_fire_event_timeout(co->link);
323         client_lock(cl);
324         non_block_events(co);
325         client_unlock(cl);
326
327         remove_connection_from_host(co);
328         yaz_mutex_leave(host->mutex);
329         connection_destroy(co);
330     }
331     else
332     {
333         yaz_mutex_leave(host->mutex);
334
335         client_lock(cl);
336         non_block_events(co);
337
338         ZOOM_connection_fire_event_socket(co->link, event);
339
340         non_block_events(co);
341         client_unlock(cl);
342
343         if (co->link)
344         {
345             iochan_setflags(iochan, ZOOM_connection_get_mask(co->link));
346             iochan_setfd(iochan, ZOOM_connection_get_socket(co->link));
347         }
348     }
349 }
350
351
352 // Disassociate connection from client
353 static void connection_release(struct connection *co)
354 {
355     struct client *cl = co->client;
356
357     if (!cl)
358         return;
359     client_set_connection(cl, 0);
360     co->client = 0;
361 }
362
363 void connect_resolver_host(struct host *host, iochan_man_t iochan_man)
364 {
365     struct connection *con;
366
367     yaz_mutex_enter(host->mutex);
368     con = host->connections;
369     while (con)
370     {
371         if (con->state == Conn_Closed)
372         {
373             if (!host->ipport || !con->client) /* unresolved or no client */
374             {
375                 remove_connection_from_host(con);
376                 yaz_mutex_leave(host->mutex);
377                 connection_destroy(con);
378             }
379             else
380             {
381                 struct session_database *sdb = client_get_database(con->client);
382                 if (sdb)
383                 {
384                     yaz_mutex_leave(host->mutex);
385                     client_start_search(con->client);
386                 }
387                 else
388                 {
389                     remove_connection_from_host(con);
390                     yaz_mutex_leave(host->mutex);
391                     connection_destroy(con);
392                 }
393             }
394             /* start all over .. at some point it will be NULL */
395             yaz_mutex_enter(host->mutex);
396             con = host->connections;
397         }
398         else
399         {
400             con = con->next;
401         }
402     }
403     yaz_mutex_leave(host->mutex);
404 }
405
406 static struct host *connection_get_host(struct connection *con)
407 {
408     return con->host;
409 }
410
411 static int connection_connect(struct connection *con, iochan_man_t iochan_man)
412 {
413     struct host *host = connection_get_host(con);
414     ZOOM_options zoptions = ZOOM_options_create();
415     const char *auth;
416     const char *charset;
417     const char *sru;
418     const char *sru_version = 0;
419     const char *value;
420     WRBUF w;
421
422     struct session_database *sdb = client_get_database(con->client);
423     const char *apdulog = session_setting_oneval(sdb, PZ_APDULOG);
424     const char *memcached = session_setting_oneval(sdb, PZ_MEMCACHED);
425     const char *redis = session_setting_oneval(sdb, PZ_REDIS);
426
427     assert(con);
428
429     ZOOM_options_set(zoptions, "async", "1");
430     ZOOM_options_set(zoptions, "implementationName", PACKAGE_NAME);
431     ZOOM_options_set(zoptions, "implementationVersion", VERSION);
432
433     if ((charset = session_setting_oneval(sdb, PZ_NEGOTIATION_CHARSET)))
434         ZOOM_options_set(zoptions, "charset", charset);
435     if (memcached && *memcached)
436         ZOOM_options_set(zoptions, "memcached", memcached);
437     if (redis && *redis)
438         ZOOM_options_set(zoptions, "redis", redis);
439
440     assert(host->ipport);
441     if (host->proxy)
442     {
443         yaz_log(YLOG_LOG, "proxy=%s", host->ipport);
444         ZOOM_options_set(zoptions, "proxy", host->ipport);
445     }
446     else
447     {
448         assert(host->tproxy);
449         yaz_log(YLOG_LOG, "tproxy=%s", host->ipport);
450         ZOOM_options_set(zoptions, "tproxy", host->ipport);
451     }
452
453     if (apdulog && *apdulog)
454         ZOOM_options_set(zoptions, "apdulog", apdulog);
455
456
457     if ((sru = session_setting_oneval(sdb, PZ_SRU)) && *sru)
458         ZOOM_options_set(zoptions, "sru", sru);
459     if ((sru_version = session_setting_oneval(sdb, PZ_SRU_VERSION))
460         && *sru_version)
461         ZOOM_options_set(zoptions, "sru_version", sru_version);
462
463     if ((auth = session_setting_oneval(sdb, PZ_AUTHENTICATION)))
464     {
465         /* allow splitting user and reset with a blank always */
466         const char *cp1 = strchr(auth, ' ');
467         if (!cp1 && sru && *sru)
468             cp1 =  strchr(auth, '/');
469         if (!cp1)
470         {
471             /* Z39.50 user/password style, or no password for SRU */
472             ZOOM_options_set(zoptions, "user", auth);
473         }
474         else
475         {
476             /* now consider group as well */
477             const char *cp2 = strchr(cp1 + 1, ' ');
478
479             ZOOM_options_setl(zoptions, "user", auth, cp1 - auth);
480             if (!cp2)
481                 ZOOM_options_set(zoptions, "password", cp1 + 1);
482             else
483             {
484                 ZOOM_options_setl(zoptions, "group", cp1 + 1, cp2 - cp1 - 1);
485                 ZOOM_options_set(zoptions, "password", cp2 + 1);
486             }
487         }
488     }
489
490     value = session_setting_oneval(sdb, PZ_AUTHENTICATION_MODE);
491     if (value && *value)
492         ZOOM_options_set(zoptions, "authenticationMode", value);
493
494     if (!(con->link = ZOOM_connection_create(zoptions)))
495     {
496         yaz_log(YLOG_FATAL|YLOG_ERRNO, "Failed to create ZOOM Connection");
497         ZOOM_options_destroy(zoptions);
498         return -1;
499     }
500
501     w = wrbuf_alloc();
502     if (sru && *sru && !strstr(con->url, "://"))
503         wrbuf_puts(w, "http://");
504     if (strchr(con->url, '#'))
505     {
506         const char *cp = strchr(con->url, '#');
507         wrbuf_write(w, con->url, cp - con->url);
508     }
509     else
510         wrbuf_puts(w, con->url);
511
512     ZOOM_connection_connect(con->link, wrbuf_cstr(w), 0);
513
514     con->iochan = iochan_create(-1, connection_handler, 0, "connection_socket");
515     con->state = Conn_Connecting;
516     iochan_settimeout(con->iochan, con->operation_timeout);
517     iochan_setdata(con->iochan, con);
518     iochan_add(iochan_man, con->iochan);
519
520     client_set_state(con->client, Client_Connecting);
521     ZOOM_options_destroy(zoptions);
522     wrbuf_destroy(w);
523     return 0;
524 }
525
526 // Ensure that client has a connection associated
527 int client_prep_connection(struct client *cl,
528                            int operation_timeout, int session_timeout,
529                            iochan_man_t iochan_man,
530                            const struct timeval *abstime)
531 {
532     struct connection *co;
533     struct session_database *sdb = client_get_database(cl);
534     const char *zproxy = session_setting_oneval(sdb, PZ_ZPROXY);
535     const char *url = session_setting_oneval(sdb, PZ_URL);
536     const char *sru = session_setting_oneval(sdb, PZ_SRU);
537     struct host *host = 0;
538     int default_port = *sru ? 80 : 210;
539
540     if (zproxy && zproxy[0] == '\0')
541         zproxy = 0;
542
543     if (!url || !*url)
544         url = sdb->database->id;
545
546     host = find_host(client_get_session(cl)->service->server->database_hosts,
547                      url, zproxy, default_port, iochan_man);
548
549     yaz_log(YLOG_DEBUG, "client_prep_connection: target=%s url=%s",
550             client_get_id(cl), url);
551     if (!host)
552         return 0;
553
554     co = client_get_connection(cl);
555     if (co)
556     {
557         assert(co->host);
558         if (co->host == host && client_get_state(cl) == Client_Idle)
559         {
560             return 2;
561         }
562         connection_release(co);
563         co = 0;
564     }
565     if (!co)
566     {
567         int max_connections = 0;
568         int reuse_connections = 1;
569         const char *v = session_setting_oneval(client_get_database(cl),
570                                                PZ_MAX_CONNECTIONS);
571         if (v && *v)
572             max_connections = atoi(v);
573
574         v = session_setting_oneval(client_get_database(cl),
575                 PZ_REUSE_CONNECTIONS);
576         if (v && *v)
577             reuse_connections = atoi(v);
578
579         // See if someone else has an idle connection
580         // We should look at timestamps here to select the longest-idle connection
581         yaz_mutex_enter(host->mutex);
582         while (1)
583         {
584             int num_connections = 0;
585             for (co = host->connections; co; co = co->next)
586                 num_connections++;
587             if (reuse_connections)
588             {
589                 for (co = host->connections; co; co = co->next)
590                 {
591                     if (connection_is_idle(co) &&
592                         !strcmp(url, co->url) &&
593                         (!co->client || client_get_state(co->client) == Client_Idle) &&
594                         !strcmp(ZOOM_connection_option_get(co->link, "user"),
595                                 session_setting_oneval(client_get_database(cl),
596                                                        PZ_AUTHENTICATION)))
597                     {
598                         if (zproxy == 0 && co->zproxy == 0)
599                             break;
600                         if (zproxy && co->zproxy && !strcmp(zproxy, co->zproxy))
601                             break;
602                     }
603                 }
604                 if (co)
605                 {
606                     yaz_log(YLOG_LOG, "num_connections = %d (reusing)", num_connections);
607                     break;
608                 }
609             }
610             if (max_connections <= 0 || num_connections < max_connections)
611             {
612                 yaz_log(YLOG_LOG, "num_connections = %d (new); max = %d",
613                         num_connections, max_connections);
614                 break;
615             }
616             yaz_log(YLOG_LOG, "num_connections = %d (waiting) max = %d",
617                     num_connections, max_connections);
618             if (yaz_cond_wait(host->cond_ready, host->mutex, abstime))
619             {
620                 yaz_log(YLOG_LOG, "out of connections %s", client_get_id(cl));
621                 client_set_state(cl, Client_Error);
622                 yaz_mutex_leave(host->mutex);
623                 return 0;
624             }
625         }
626         if (co)
627         {
628             yaz_log(YLOG_LOG,  "%p Connection reuse. state: %d", co, co->state);
629             connection_release(co);
630             client_set_connection(cl, co);
631             co->client = cl;
632             /* ensure that connection is only assigned to this client
633                by marking the client non Idle */
634             client_set_state(cl, Client_Working);
635             yaz_mutex_leave(host->mutex);
636             co->operation_timeout = operation_timeout;
637             co->session_timeout = session_timeout;
638             /* tells ZOOM to reconnect if necessary. Disabled becuase
639                the ZOOM_connection_connect flushes the task queue */
640             ZOOM_connection_connect(co->link, 0, 0);
641         }
642         else
643         {
644             yaz_mutex_leave(host->mutex);
645             co = connection_create(cl, url, host,
646                                    operation_timeout, session_timeout,
647                                    iochan_man);
648         }
649         assert(co->host);
650     }
651
652     if (co && co->link)
653         return 1;
654     else
655         return 0;
656 }
657
658 /*
659  * Local variables:
660  * c-basic-offset: 4
661  * c-file-style: "Stroustrup"
662  * indent-tabs-mode: nil
663  * End:
664  * vim: shiftwidth=4 tabstop=8 expandtab
665  */
666