added an info log line to log the called method
[OpenSRF.git] / src / perlmods / OpenSRF / Application.pm
1 package OpenSRF::Application;
2 use vars qw/$_app $log @_METHODS $thunk $server_class/;
3
4 use base qw/OpenSRF/;
5 use OpenSRF::AppSession;
6 use OpenSRF::DomainObject::oilsMethod;
7 use OpenSRF::DomainObject::oilsResponse qw/:status/;
8 use OpenSRF::Utils::Logger qw/:level $logger/;
9 use Data::Dumper;
10 use Time::HiRes qw/time/;
11 use OpenSRF::EX qw/:try/;
12 use Carp;
13 use JSON;
14 #use OpenSRF::UnixServer;  # to get the server class from UnixServer::App
15
16 sub DESTROY{};
17
18 use strict;
19 use warnings;
20
21 $log = 'OpenSRF::Utils::Logger';
22
23 our $in_request = 0;
24 our @pending_requests;
25
26 sub package {
27         my $self = shift;
28         return 1 unless ref($self);
29         return $self->{package};
30 }
31
32 sub signature {
33         my $self = shift;
34         return 0 unless ref($self);
35         return $self->{signature};
36 }
37
38 sub argc {
39         my $self = shift;
40         return 0 unless ref($self);
41         return $self->{argc};
42 }
43
44 sub api_name {
45         my $self = shift;
46         return 1 unless ref($self);
47         return $self->{api_name};
48 }
49
50 sub api_level {
51         my $self = shift;
52         return 1 unless ref($self);
53         return $self->{api_level};
54 }
55
56 sub server_class {
57         my $class = shift;
58         if($class) {
59                 $server_class = $class;
60         }
61         return $server_class;
62 }
63
64 sub thunk {
65         my $self = shift;
66         my $flag = shift;
67         $thunk = $flag if (defined $flag);
68         return $thunk;
69 }
70
71 sub application_implementation {
72         my $self = shift;
73         my $app = shift;
74
75         if (defined $app) {
76                 $_app = $app;
77                 $_app->use;
78                 if( $@ ) {
79                         $log->error( "Error loading application_implementation: $app -> $@", ERROR);
80                 }
81
82         }
83
84         return $_app;
85 }
86
87 sub handler {
88         my ($self, $session, $app_msg) = @_;
89
90         if( ! $app_msg ) {
91                 return 1;  # error?
92         }
93
94         my $app = $self->application_implementation;
95
96         if ($session->last_message_type eq 'REQUEST') {
97
98         my @p = $app_msg->params;
99                 my $method_name = $app_msg->method;
100                 my $method_proto = $session->last_message_api_level;
101         $logger->info("CALL: $method_name [".join(', ',@p)."]");
102
103                 my $coderef = $app->method_lookup( $method_name, $method_proto, 1, 1 );
104
105                 unless ($coderef) {
106                         $session->status( OpenSRF::DomainObject::oilsMethodException->new( 
107                                                 statusCode => STATUS_NOTFOUND(),
108                                                 status => "Method [$method_name] not found for $app"));
109                         return 1;
110                 }
111
112                 unless ($session->continue_request) {
113                         $session->status(
114                                 OpenSRF::DomainObject::oilsConnectStatus->new(
115                                                 statusCode => STATUS_REDIRECTED(),
116                                                 status => 'Disconnect on max requests' ) );
117                         $session->kill_me;
118                         return 1;
119                 }
120
121                 if (ref $coderef) {
122                         my @args = $app_msg->params;
123                         my $appreq = OpenSRF::AppRequest->new( $session );
124
125                         $log->debug( "in_request = $in_request : [" . $appreq->threadTrace."]", INTERNAL );
126                         if( $in_request ) {
127                                 $log->debug( "Pushing onto pending requests: " . $appreq->threadTrace, DEBUG );
128                                 push @pending_requests, [ $appreq, \@args, $coderef ]; 
129                                 return 1;
130                         }
131
132
133                         $in_request++;
134
135                         $log->debug( "Executing coderef for {$method_name}", INTERNAL );
136
137                         my $resp;
138                         try {
139                                 # un-if(0) this block to enable param checking based on signature and argc
140                                 if (0) {
141                                         if (@args < $coderef->argc) {
142                                                 die     "Not enough params passed to ".
143                                                         $coderef->api_name." : requires ". $coderef->argc
144                                         }
145                                         if (@args) {
146                                                 my $sig = $coderef->signature;
147                                                 if ($sig && exists $sig->{params}) {
148                                                         for my $p (0 .. scalar(@{ $sig->{params} }) - 1 ) {
149                                                                 my $s = $sig->{params}->[$p];
150                                                                 my $a = $args[$p];
151                                                                 if ($s->{class} && JSON->lookup_hint(ref $a) ne $s->{class}) {
152                                                                         die "Incorrect param class at position $p : should be a '$$s{class}'";
153                                                                 } elsif ($s->{type}) {
154                                                                         if (lc($s->{type}) eq 'object' && $a !~ /HASH/o) {
155                                                                                 die "Incorrect param type at position $p : should be an 'object'";
156                                                                         } elsif (lc($s->{type}) eq 'array' && $a !~ /ARRAY/o) {
157                                                                                 die "Incorrect param type at position $p : should be an 'array'";
158                                                                         } elsif (lc($s->{type}) eq 'number' && (ref($a) || $a !~ /^-?\d+(?:\.\d+)?$/o)) {
159                                                                                 die "Incorrect param type at position $p : should be a 'number'";
160                                                                         } elsif (lc($s->{type}) eq 'string' && ref($a)) {
161                                                                                 die "Incorrect param type at position $p : should be a 'string'";
162                                                                         }
163                                                                 }
164                                                         }
165                                                 }
166                                         }
167                                 }
168
169                                 my $start = time();
170                                 $resp = $coderef->run( $appreq, @args); 
171                                 my $time = sprintf '%.3f', time() - $start;
172
173                                 $log->debug( "Method duration for [$method_name]:  ". $time );
174                                 if( defined( $resp ) ) {
175                                         $appreq->respond_complete( $resp );
176                                 } else {
177                                         $appreq->status( OpenSRF::DomainObject::oilsConnectStatus->new(
178                                                                 statusCode => STATUS_COMPLETE(),
179                                                                 status => 'Request Complete' ) );
180                                 }
181                         } catch Error with {
182                                 my $e = shift;
183                                 warn "Caught error from 'run' method: $e\n";
184
185                                 if(UNIVERSAL::isa($e,"Error")) {
186                                         $e = $e->stringify();
187                                 } 
188                                 my $sess_id = $session->session_id;
189                                 $session->status(
190                                         OpenSRF::DomainObject::oilsMethodException->new(
191                                                         statusCode      => STATUS_INTERNALSERVERERROR(),
192                                                         status          => " *** Call to [$method_name] failed for session ".
193                                                                            "[$sess_id], thread trace ".
194                                                                            "[".$appreq->threadTrace."]:\n$e\n"
195                                         )
196                                 );
197                         };
198
199
200
201                         # ----------------------------------------------
202
203
204                         # XXX may need this later
205                         # $_->[1] = 1 for (@OpenSRF::AppSession::_CLIENT_CACHE);
206
207                         $in_request--;
208
209                         $log->debug( "Pending Requests: " . scalar(@pending_requests), INTERNAL );
210
211                         # cycle through queued requests
212                         while( my $aref = shift @pending_requests ) {
213                                 $in_request++;
214                                 my $resp;
215                                 try {
216                                         # un-if(0) this block to enable param checking based on signature and argc
217                                         if (0) {
218                                                 if (@args < $aref->[2]->argc) {
219                                                         die     "Not enough params passed to ".
220                                                                 $aref->[2]->api_name." : requires ". $aref->[2]->argc
221                                                 }
222                                                 if (@args) {
223                                                         my $sig = $aref->[2]->signature;
224                                                         if ($sig && exists $sig->{params}) {
225                                                                 for my $p (0 .. scalar(@{ $sig->{params} }) - 1 ) {
226                                                                         my $s = $sig->{params}->[$p];
227                                                                         my $a = $args[$p];
228                                                                         if ($s->{class} && JSON->lookup_hint(ref $a) ne $s->{class}) {
229                                                                                 die "Incorrect param class at position $p : should be a '$$s{class}'";
230                                                                         } elsif ($s->{type}) {
231                                                                                 if (lc($s->{type}) eq 'object' && $a !~ /HASH/o) {
232                                                                                         die "Incorrect param type at position $p : should be an 'object'";
233                                                                                 } elsif (lc($s->{type}) eq 'array' && $a !~ /ARRAY/o) {
234                                                                                         die "Incorrect param type at position $p : should be an 'array'";
235                                                                                 } elsif (lc($s->{type}) eq 'number' && (ref($a) || $a !~ /^-?\d+(?:\.\d+)?$/o)) {
236                                                                                         die "Incorrect param type at position $p : should be a 'number'";
237                                                                                 } elsif (lc($s->{type}) eq 'string' && ref($a)) {
238                                                                                         die "Incorrect param type at position $p : should be a 'string'";
239                                                                                 }
240                                                                         }
241                                                                 }
242                                                         }
243                                                 }
244                                         }
245
246                                         my $start = time;
247                                         my $response = $aref->[2]->run( $aref->[0], @{$aref->[1]} );
248                                         my $time = sprintf '%.3f', time - $start;
249                                         $log->debug( "Method duration for [".$aref->[2]->api_name." -> ".join(', ',@{$aref->[1]}).']:  '.$time, DEBUG );
250
251                                         $appreq = $aref->[0];   
252                                         if( ref( $response ) ) {
253                                                 $appreq->respond_complete( $response );
254                                         } else {
255                                                 $appreq->status( OpenSRF::DomainObject::oilsConnectStatus->new(
256                                                                         statusCode => STATUS_COMPLETE(),
257                                                                         status => 'Request Complete' ) );
258                                         }
259                                         $log->debug( "Executed: " . $appreq->threadTrace, INTERNAL );
260                                 } catch Error with {
261                                         my $e = shift;
262                                         if(UNIVERSAL::isa($e,"Error")) {
263                                                 $e = $e->stringify();
264                                         }
265                                         $session->status(
266                                                 OpenSRF::DomainObject::oilsMethodException->new(
267                                                                 statusCode => STATUS_INTERNALSERVERERROR(),
268                                                                 status => "Call to [".$aref->[2]->api_name."] faild:  $e"
269                                                 )
270                                         );
271                                 };
272                                 $in_request--;
273                         }
274
275                         return 1;
276                 } 
277
278                 $log->info("Received non-REQUEST message in Application handler");
279
280                 my $res = OpenSRF::DomainObject::oilsMethodException->new( 
281                                 status => "Received non-REQUEST message in Application handler");
282                 $session->send('ERROR', $res);
283                 $session->kill_me;
284                 return 1;
285
286         } else {
287                 $session->push_queue([ $app_msg, $session->last_threadTrace ]);
288         }
289
290         $session->last_message_type('');
291         $session->last_message_api_level('');
292
293         return 1;
294 }
295
296 sub is_registered {
297         my $self = shift;
298         my $api_name = shift;
299         my $api_level = shift || 1;
300         return exists($_METHODS[$api_level]{$api_name});
301 }
302
303
304 sub normalize_whitespace {
305         my $txt = shift;
306
307         $txt =~ s/^\s+//gso;
308         $txt =~ s/\s+$//gso;
309         $txt =~ s/\s+/ /gso;
310         $txt =~ s/\n//gso;
311         $txt =~ s/\. /\.  /gso;
312
313         return $txt;
314 }
315
316 sub parse_string_signature {
317         my $string = shift;
318         return [] unless $string;
319         my @chunks = split(/\@/so, $string);
320
321         my @params;
322         my $ret;
323         my $desc = '';
324         for (@chunks) {
325                 if (/^return (.+)$/so) {
326                         $ret = [normalize_whitespace($1)];
327                 } elsif (/^param (\w+) \b(.+)$/so) {
328                         push @params, [ $1, normalize_whitespace($2) ];
329                 } else {
330                         $desc .= '@' if $desc;
331                         $desc .= $_;
332                 }
333         }
334
335         return [normalize_whitespace($desc),\@params, $ret];
336 }
337
338 sub parse_array_signature {
339         my $array = shift;
340         my ($d,$p,$r) = @$array;
341         return {} unless ($d or $p or $r);
342
343         return {
344                 desc    => $d,
345                 params  => [
346                         map { 
347                                 { name  => $$_[0],
348                                   desc  => $$_[1],
349                                   type  => $$_[2],
350                                   class => $$_[3],
351                                 }
352                         } @$p
353                 ],
354                 'return'=>
355                         { desc  => $$r[0],
356                           type  => $$r[1],
357                           class => $$r[2],
358                         }
359         };
360 }
361
362 sub register_method {
363         my $self = shift;
364         my $app = ref($self) || $self;
365         my %args = @_;
366
367
368         throw OpenSRF::DomainObject::oilsMethodException unless ($args{method});
369
370         $args{api_level} = 1 unless(defined($args{api_level}));
371         $args{stream} ||= 0;
372         $args{remote} ||= 0;
373         $args{argc} ||= 0;
374         $args{package} ||= $app;                
375         $args{server_class} = server_class();
376         $args{api_name} ||= $args{server_class} . '.' . $args{method};
377
378         # un-if(0) this block to enable signature parsing
379         if (!$args{signature}) {
380                 if ($args{notes} && !ref($args{notes})) {
381                         $args{signature} =
382                                 parse_array_signature( parse_string_signature( $args{notes} ) );
383                 }
384         } elsif( !ref($args{signature}) ) {
385                 $args{signature} =
386                         parse_array_signature( parse_string_signature( $args{signature} ) );
387         } elsif( ref($args{signature}) eq 'ARRAY') {
388                 $args{signature} =
389                         parse_array_signature( $args{signature} );
390         }
391         
392         unless ($args{object_hint}) {
393                 ($args{object_hint} = $args{package}) =~ s/::/_/go;
394         }
395
396         JSON->register_class_hint( name => $args{package}, hint => $args{object_hint}, type => "hash" );
397
398         $_METHODS[$args{api_level}]{$args{api_name}} = bless \%args => $app;
399
400         __PACKAGE__->register_method(
401                 stream => 0,
402                 argc => $args{argc},
403                 api_name => $args{api_name}.'.atomic',
404                 method => 'make_stream_atomic',
405                 notes => "This is a system generated method.  Please see the definition for $args{api_name}",
406         ) if ($args{stream});
407 }
408
409 sub retrieve_remote_apis {
410         my $method = shift;
411         my $session = OpenSRF::AppSession->create('router');
412         try {
413                 $session->connect or OpenSRF::EX::WARN->throw("Connection to router timed out");
414         } catch Error with {
415                 my $e = shift;
416                 $log->debug( "Remote subrequest returned an error:\n". $e );
417                 return undef;
418         } finally {
419                 return undef unless ($session->state == $session->CONNECTED);
420         };
421
422         my $req = $session->request( 'opensrf.router.info.class.list' );
423         my $list = $req->recv;
424
425         if( UNIVERSAL::isa($list,"Error") ) {
426                 throw $list;
427         }
428
429         my $content = $list->content;
430
431         $req->finish;
432         $session->finish;
433         $session->disconnect;
434
435         my %u_list = map { ($_ => 1) } @$content;
436
437         for my $class ( keys %u_list ) {
438                 next if($class eq $server_class);
439                 populate_remote_method_cache($class, $method);
440         }
441 }
442
443 sub populate_remote_method_cache {
444         my $class = shift;
445         my $meth = shift;
446
447         my $session = OpenSRF::AppSession->create($class);
448         try {
449                 $session->connect or OpenSRF::EX::WARN->throw("Connection to $class timed out");
450
451                 my $call = 'opensrf.system.method.all' unless (defined $meth);
452                 $call = 'opensrf.system.method' if (defined $meth);
453
454                 my $req = $session->request( $call, $meth );
455
456                 while (my $method = $req->recv) {
457                         next if (UNIVERSAL::isa($method, 'Error'));
458
459                         $method = $method->content;
460                         next if ( exists($_METHODS[$$method{api_level}]) &&
461                                 exists($_METHODS[$$method{api_level}]{$$method{api_name}}) );
462                         $method->{remote} = 1;
463                         bless($method, __PACKAGE__ );
464                         $_METHODS[$$method{api_level}]{$$method{api_name}} = $method;
465                 }
466
467                 $req->finish;
468                 $session->finish;
469                 $session->disconnect;
470
471         } catch Error with {
472                 my $e = shift;
473                 $log->debug( "Remote subrequest returned an error:\n". $e );
474                 return undef;
475         };
476 }
477
478 sub method_lookup {             
479         my $self = shift;
480         my $method = shift;
481         my $proto = shift;
482         my $no_recurse = shift || 0;
483         my $no_remote = shift || 0;
484
485         # this instead of " || 1;" above to allow api_level 0
486         $proto = $self->api_level unless (defined $proto);
487
488         my $class = ref($self) || $self;
489
490         $log->debug("Lookup of [$method] by [$class] in api_level [$proto]", DEBUG);
491         $log->debug("Available methods\n\t".join("\n\t", keys %{ $_METHODS[$proto] }), INTERNAL);
492
493         my $meth;
494         if (__PACKAGE__->thunk) {
495                 for my $p ( reverse(1 .. $proto) ) {
496                         if (exists $_METHODS[$p]{$method}) {
497                                 $meth = $_METHODS[$p]{$method};
498                         }
499                 }
500         } else {
501                 if (exists $_METHODS[$proto]{$method}) {
502                         $meth = $_METHODS[$proto]{$method};
503                 }
504         }
505
506         if (defined $meth) {
507                 if($no_remote and $meth->{remote}) {
508                         $log->debug("OH CRAP We're not supposed to return remote methods", WARN);
509                         return undef;
510                 }
511
512         } elsif (!$no_recurse) {
513                 $log->debug("We didn't find [$method], asking everyone else.", DEBUG);
514                 retrieve_remote_apis($method);
515                 $meth = $self->method_lookup($method,$proto,1);
516         }
517
518         return $meth;
519 }
520
521 sub run {
522         my $self = shift;
523         my $req = shift;
524
525         my $resp;
526         my @params = @_;
527
528         if ( !UNIVERSAL::isa($req, 'OpenSRF::AppRequest') ) {
529                 $log->debug("Creating a SubRequest object", DEBUG);
530                 unshift @params, $req;
531                 $req = OpenSRF::AppSubrequest->new;
532         } else {
533                 $log->debug("This is a top level request", DEBUG);
534         }
535
536         if (!$self->{remote}) {
537                 my $code = \&{$self->{package} . '::' . $self->{method}};
538                 my $err = undef;
539
540                 try {
541                         $resp = $code->($self, $req, @params);
542
543                 } catch Error with {
544                         $err = shift;
545
546                         if( ref($self) eq 'HASH') {
547                                 $log->error("Sub $$self{package}::$$self{method} DIED!!!\n\t$err\n", ERROR);
548                         }
549                 };
550
551                 if($err) {
552                         if(UNIVERSAL::isa($err,"Error")) { 
553                                 throw $err;
554                         } else {
555                                 die $err->stringify; 
556                         }
557                 }
558
559
560                 $log->debug("Coderef for [$$self{package}::$$self{method}] has been run", DEBUG);
561
562                 if ( ref($req) and UNIVERSAL::isa($req, 'OpenSRF::AppSubrequest') ) {
563                         $req->respond($resp) if (defined $resp);
564                         $log->debug("SubRequest object is responding with : " . join(" ",$req->responses), DEBUG);
565                         return $req->responses;
566                 } else {
567                         $log->debug("A top level Request object is responding $resp", DEBUG) if (defined $resp);
568                         return $resp;
569                 }
570         } else {
571                 my $session = OpenSRF::AppSession->create($self->{server_class});
572                 try {
573                         #$session->connect or OpenSRF::EX::WARN->throw("Connection to [$$self{server_class}] timed out");
574                         my $remote_req = $session->request( $self->{api_name}, @params );
575                         while (my $remote_resp = $remote_req->recv) {
576                                 OpenSRF::Utils::Logger->debug("Remote Subrequest Received " . $remote_resp, INTERNAL );
577                                 if( UNIVERSAL::isa($remote_resp,"Error") ) {
578                                         throw $remote_resp;
579                                 }
580                                 $req->respond( $remote_resp->content );
581                         }
582                         $remote_req->finish();
583
584                 } catch Error with {
585                         my $e = shift;
586                         $log->debug( "Remote subrequest returned an error:\n". $e );
587                         return undef;
588                 };
589
590                 if ($session) {
591                         $session->disconnect();
592                         $session->finish();
593                 }
594
595                 $log->debug( "Remote Subrequest Responses " . join(" ", $req->responses), INTERNAL );
596
597                 return $req->responses;
598         }
599         # huh? how'd we get here...
600         return undef;
601 }
602
603 sub introspect {
604         my $self = shift;
605         my $client = shift;
606         my $method = shift;
607         my $limit = shift;
608         my $offset = shift;
609
610         if ($self->api_name =~ /all$/o) {
611                 $offset = $limit;
612                 $limit = $method;
613                 $method = undef; 
614         }
615
616         my ($seen,$returned) = (0,0);
617         for my $api_level ( reverse(1 .. $#_METHODS) ) {
618                 for my $api_name ( sort keys %{$_METHODS[$api_level]} ) {
619                         if (!$offset || $offset <= $seen) {
620                                 if (!$_METHODS[$api_level]{$api_name}{remote}) {
621                                         if (defined($method)) {
622                                                 if ($api_name =~ $method) {
623                                                         if (!$limit || $returned < $limit) {
624                                                                 $client->respond( $_METHODS[$api_level]{$api_name} );
625                                                                 $returned++;
626                                                         }
627                                                 }
628                                         } else {
629                                                 if (!$limit || $returned < $limit) {
630                                                         $client->respond( $_METHODS[$api_level]{$api_name} );
631                                                         $returned++;
632                                                 }
633                                         }
634                                 }
635                         }
636                         $seen++;
637                 }
638         }
639
640         return undef;
641 }
642 __PACKAGE__->register_method(
643         stream => 1,
644         method => 'introspect',
645         api_name => 'opensrf.system.method.all',
646         argc => 0,
647         signature => {
648                 desc => q/This method is used to introspect an entire OpenSRF Application/,
649                 return => {
650                         desc => q/A stream of objects describing the methods available via this OpenSRF Application/,
651                         type => 'object'
652                 }
653         },
654 );
655 __PACKAGE__->register_method(
656         stream => 1,
657         method => 'introspect',
658         argc => 1,
659         api_name => 'opensrf.system.method',
660         argc => 1,
661         signature => {
662                 desc => q/Use this method to get the definition of a single OpenSRF Method/,
663                 params => [
664                         { desc => q/The method to introspect/,
665                           type => 'string' },
666                 ],
667                 return => { desc => q/An object describing the method requested, or an error if it can't be found/,
668                             type => 'object' }
669         },
670 );
671
672 sub echo_method {
673         my $self = shift;
674         my $client = shift;
675         my @args = @_;
676
677         $client->respond( $_ ) for (@args);
678         return undef;
679 }
680 __PACKAGE__->register_method(
681         stream => 1,
682         method => 'echo_method',
683         argc => 1,
684         api_name => 'opensrf.system.echo',
685         signature => {
686                 desc => q/A test method that will echo back it's arguments in a streaming response/,
687                 params => [
688                         { desc => q/One or more arguments to echo back/ }
689                 ],
690                 return => { desc => q/A stream of the arguments passed/ }
691         },
692 );
693
694 sub time_method {
695         my( $self, $conn ) = @_;
696         return CORE::time;
697 }
698 __PACKAGE__->register_method(
699         method => 'time_method',
700         argc => 0,
701         api_name => 'opensrf.system.time',
702         signature => {
703                 desc => q/Returns the current system time as epoch seconds/,
704                 return => { desc => q/epoch seconds/ }
705         }
706 );
707
708 sub make_stream_atomic {
709         my $self = shift;
710         my $req = shift;
711         my @args = @_;
712
713         (my $m_name = $self->api_name) =~ s/\.atomic$//o;
714         my @results = $self->method_lookup($m_name)->run(@args);
715
716         return \@results;
717 }
718
719
720 1;
721
722