gearpump-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Karol Brejna (JIRA)" <j...@apache.org>
Subject [jira] [Created] (GEARPUMP-154) Ambiguous response when submitting a dag (with error in main() )
Date Mon, 06 Jun 2016 14:34:21 GMT
Karol Brejna created GEARPUMP-154:
-------------------------------------

             Summary: Ambiguous response when submitting a dag (with error in main() )
                 Key: GEARPUMP-154
                 URL: https://issues.apache.org/jira/browse/GEARPUMP-154
             Project: Apache Gearpump
          Issue Type: Task
            Reporter: Karol Brejna


When a dag is deployed and some error occurs in main(), the error message (resulting http
response text) is ambiguous.

Example piece of pseudo-code of main:
{code}
		ClientContext context = ClientContext.apply();
		UserConfig appConfig = UserConfig.empty();
		try {
			extractParameters(ClusterConfig.defaultConfig());
		} catch (Exception e) {
			System.err.println(e.getMessage());
			System.err.println("Check input parameters.");
			throw new IllegalArgumentException("Check input parameters.", e);
        }
{code}

extractParameters throws an exception.

Submitting the app (/api/v1.0/master/submitapp) results in the following response:

{code}
500: java.io.IOException: Process exit abnormally with exit code 1.
Error message: 
[INFO] [06/06/2016 09:55:27.986] [ClusterConfig$] loading config file /home/vcap/tmp/"userfile_configstring_10591982582233655.conf..........
[INFO] [06/06/2016 09:55:28.097] [ClusterConfig$] loading config file /home/vcap/tmp/"userfile_configstring_10591982582233655.conf..........
[INFO] [06/06/2016 09:55:28.119] [ClusterConfig$] loading config file /home/vcap/tmp/"userfile_configstring_10591982582233655.conf..........
[INFO] [06/06/2016 09:55:28.431] [Slf4jLogger] Slf4jLogger started
[INFO] [06/06/2016 09:55:28.531] [Remoting] Starting remoting
[INFO] [06/06/2016 09:55:28.676] [Remoting] Remoting started; listening on addresses :[akka.tcp://client546592650@127.0.0.1:39396]
[INFO] [06/06/2016 09:55:28.702] [Metrics$] Metrics is enabled...,  false
[INFO] [06/06/2016 09:55:28.705] [ClientContext] Starting system client546592650
No configuration setting found for key 'tap.usersArgs'
Check input parameters.
[INFO] [06/06/2016 09:55:28.725] [MasterProxy@masterproxy326214661] Contacts point URL: akka.tcp://master@cdh-worker-2.node.envname.consul:54618/user/master
	at io.gearpump.services.MasterService$.submitAndDeleteTempFiles(MasterService.scala:269)
	at io.gearpump.services.MasterService$.submitGearApp(MasterService.scala:227)
	at io.gearpump.services.MasterService$$anonfun$doRoute$1$$anonfun$apply$46$$anonfun$apply$47$$anonfun$apply$48$$anonfun$apply$49$$anonfun$apply$1.apply$mcZ$sp(MasterService.scala:126)
	at io.gearpump.services.MasterService$$anonfun$doRoute$1$$anonfun$apply$46$$anonfun$apply$47$$anonfun$apply$48$$anonfun$apply$49$$anonfun$apply$1.apply(MasterService.scala:126)
	at io.gearpump.services.MasterService$$anonfun$doRoute$1$$anonfun$apply$46$$anonfun$apply$47$$anonfun$apply$48$$anonfun$apply$49$$anonfun$apply$1.apply(MasterService.scala:126)
	at scala.concurrent.impl.Future$PromiseCompletingRunnable.liftedTree1$1(Future.scala:24)
	at scala.concurrent.impl.Future$PromiseCompletingRunnable.run(Future.scala:24)
	at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:39)
	at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(AbstractDispatcher.scala:405)
	at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
	at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
	at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
	at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
{code}

and the corresponding log entries:

First part:
{code}
2016-06-06T16:20:56.77+0200 [App/0]      ERR [INFO] [06/06/2016 14:20:56.777] [Util$] Starting
executor process java io.gearpump.cluster.main.AppSubmitter -jar /home/vcap/tmp/userfile_jar_8939349832720298328gearpump-app-0.5.1-jar-with-dependencies.jar
-executors 1
2016-06-06T16:20:56.77+0200 [App/0]      ERR  -Dgearpump.home=/home/vcap/app -Dgearpump.hostname=127.0.0.1
-Djava.net.preferIPv4Stack=true -Dgearpump.cluster.masters.0=cdh-worker-2.node.envname.consul:54618
-Dgearpump.config.file=/home/vcap/tmp/"userfile_configstring_500006396416965605.conf
2016-06-06T16:20:57.15+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.153] [redirect]
[INFO] [06/06/2016 14:20:57.152] [ClusterConfig$] loading config file /home/vcap/tmp/"userfile_configstring_500006396416965605.conf..........
2016-06-06T16:20:57.26+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.262] [redirect]
[INFO] [06/06/2016 14:20:57.262] [ClusterConfig$] loading config file /home/vcap/tmp/"userfile_configstring_500006396416965605.conf..........
2016-06-06T16:20:57.28+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.286] [redirect]
[INFO] [06/06/2016 14:20:57.286] [ClusterConfig$] loading config file /home/vcap/tmp/"userfile_configstring_500006396416965605.conf..........
2016-06-06T16:20:57.60+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.603] [redirect]
[INFO] [06/06/2016 14:20:57.603] [Slf4jLogger] Slf4jLogger started
2016-06-06T16:20:57.70+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.700] [redirect]
[INFO] [06/06/2016 14:20:57.700] [Remoting] Starting remoting
2016-06-06T16:20:57.85+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.851] [redirect]
[INFO] [06/06/2016 14:20:57.850] [Remoting] Remoting started; listening on addresses :[akka.tcp://client1037924143@127.0.0.1:38333]
2016-06-06T16:20:57.87+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.879] [redirect]
[INFO] [06/06/2016 14:20:57.879] [Metrics$] Metrics is enabled...,  false
2016-06-06T16:20:57.88+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.882] [redirect]
[INFO] [06/06/2016 14:20:57.882] [ClientContext] Starting system client1037924143
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.900] [redirect]
No configuration setting found for key 'tap.usersArgs'
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.901] [redirect]
Check input parameters.
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.902] [redirect]
[INFO] [06/06/2016 14:20:57.902] [MasterProxy@masterproxy2012533134] Contacts point URL: akka.tcp://master@cdh-worker-2.node.envname.consul:54618/user/master
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.903] [redirect]
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.904] [redirect]
Help: Submit an application to Master by providing a jar
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.905] [redirect]
[INFO] [06/06/2016 14:20:57.905] [MasterProxy@masterproxy2012533134] Master Proxy is started...
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.905] [redirect]
-namePrefix (required:false, default:)<application name prefix>
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.906] [redirect]
-jar (required:true)<application>.jar
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.906] [redirect]
-executors (required:false, default:1)number of executor to launch
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.906] [redirect]
-verbose (required:false, default:false)<print verbose log on console>
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.907] [redirect]
-conf (required:false, default:)custom configuration file
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.907] [redirect]
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.908] [redirect]
Exception in thread "main" java.lang.reflect.InvocationTargetException
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.908] [redirect]
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.909] [redirect]
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.909] [redirect]
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.909] [redirect]
      at java.lang.reflect.Method.invoke(Method.java:497)
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.909] [redirect]
      at io.gearpump.cluster.main.AppSubmitter$.main(AppSubmitter.scala:87)
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.909] [redirect]
      at io.gearpump.util.AkkaApp$$anonfun$main$1.apply(AkkaApp.scala:25)
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.909] [redirect]
      at io.gearpump.util.AkkaApp$$anonfun$main$1.apply(AkkaApp.scala:25)
2016-06-06T16:20:57.90+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.909] [redirect]
      at scala.util.Try$.apply(Try.scala:192)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.909] [redirect]
      at io.gearpump.util.AkkaApp$class.main(AkkaApp.scala:24)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.909] [redirect]
      at io.gearpump.cluster.main.AppSubmitter$.main(AppSubmitter.scala:30)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
      at io.gearpump.cluster.main.AppSubmitter.main(AppSubmitter.scala)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
Caused by: java.lang.IllegalArgumentException: Check input parameters.
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
      at PipelineApp.main(PipelineApp.java:61)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
      at PipelineApp.main(PipelineApp.java:49)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
      ... 11 more
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
Caused by: com.typesafe.config.ConfigException$Missing: No configuration setting found for
key 'tap.usersArgs'
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
      at com.typesafe.config.impl.SimpleConfig.findKeyOrNull(SimpleConfig.java:152)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
      at com.typesafe.config.impl.SimpleConfig.findKey(SimpleConfig.java:145)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
      at com.typesafe.config.impl.SimpleConfig.findOrNull(SimpleConfig.java:172)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
      at com.typesafe.config.impl.SimpleConfig.findOrNull(SimpleConfig.java:176)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
      at com.typesafe.config.impl.SimpleConfig.find(SimpleConfig.java:184)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
      at com.typesafe.config.impl.SimpleConfig.find(SimpleConfig.java:189)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
      at com.typesafe.config.impl.SimpleConfig.getString(SimpleConfig.java:246)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.910] [redirect]
      at PipelineApp.extractParameters(PipelineApp.java:122)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.911] [redirect]
      at PipelineApp.main(PipelineApp.java:57)
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.911] [redirect]
      ... 12 more
2016-06-06T16:20:57.91+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:57.911] [redirect]
[INFO] [06/06/2016 14:20:57.905] [MasterProxy@masterproxy2012533134] sending identity to ActorSelection[Anchor(akka.tcp://master@cdh-worker-2.node.envname.consul:54618/),
Path(/user/master)]
{code}

Second part:
{code}
2016-06-06T16:20:58.24+0200 [RTR/0]      OUT gearpump-ui-45726a55-e4d9-4e01-8be9-670c95c66c28-7dc127ab.dev-nokrb.gotapaas.eu
- [06/06/2016:14:20:55 +0000] "POST /api/v1.0/master/submitapp HTTP/1.1" 500 50259538 2525
"http://console.dev-nokrb.gotapaas.eu/" "Mozilla/5.0 (Windows NT 6.3; WOW64) AppleWebKit/537.36
(KHTML, like Gecko) Chrome/51.0.2704.79 Safari/537.36" 10.0.0.52:60460 x_forwarded_for:"52.58.161.175"
x_forwarded_proto:"http" vcap_request_id:f3ed3d7f-3c18-4bd9-6fed-7ed7bdc6fad1 response_time:2.405568639
app_id:d5bea433-faaa-4d31-b2e4-c5f2214cce7f
2016-06-06T16:20:58.24+0200 [App/0]      ERR [ERROR] [06/06/2016 14:20:58.241] [RestServices]
Request to http://gearpump-ui-45726a55-e4d9-4e01-8be9-670c95c66c28-7dc127ab.dev-nokrb.gotapaas.eu/api/v1.0/master/submitapp
could not be handled normally
2016-06-06T16:20:58.24+0200 [App/0]      ERR java.io.IOException: Process exit abnormally
with exit code 1.
2016-06-06T16:20:58.24+0200 [App/0]      ERR Error message:
2016-06-06T16:20:58.24+0200 [App/0]      ERR [INFO] [06/06/2016 14:20:57.152] [ClusterConfig$]
loading config file /home/vcap/tmp/"userfile_configstring_500006396416965605.conf..........
2016-06-06T16:20:58.24+0200 [App/0]      ERR [INFO] [06/06/2016 14:20:57.262] [ClusterConfig$]
loading config file /home/vcap/tmp/"userfile_configstring_500006396416965605.conf..........
2016-06-06T16:20:58.24+0200 [App/0]      ERR [INFO] [06/06/2016 14:20:57.286] [ClusterConfig$]
loading config file /home/vcap/tmp/"userfile_configstring_500006396416965605.conf..........
2016-06-06T16:20:58.24+0200 [App/0]      ERR [INFO] [06/06/2016 14:20:57.603] [Slf4jLogger]
Slf4jLogger started
2016-06-06T16:20:58.24+0200 [App/0]      ERR [INFO] [06/06/2016 14:20:57.700] [Remoting] Starting
remoting
2016-06-06T16:20:58.24+0200 [App/0]      ERR [INFO] [06/06/2016 14:20:57.850] [Remoting] Remoting
started; listening on addresses :[akka.tcp://client1037924143@127.0.0.1:38333]
2016-06-06T16:20:58.24+0200 [App/0]      ERR [INFO] [06/06/2016 14:20:57.879] [Metrics$] Metrics
is enabled...,  false
2016-06-06T16:20:58.24+0200 [App/0]      ERR [INFO] [06/06/2016 14:20:57.882] [ClientContext]
Starting system client1037924143
2016-06-06T16:20:58.24+0200 [App/0]      ERR No configuration setting found for key 'tap.usersArgs'
2016-06-06T16:20:58.24+0200 [App/0]      ERR Check input parameters.
2016-06-06T16:20:58.24+0200 [App/0]      ERR [INFO] [06/06/2016 14:20:57.902] [MasterProxy@masterproxy2012533134]
Contacts point URL: akka.tcp://master@cdh-worker-2.node.envname.consul:54618/user/master
2016-06-06T16:20:58.24+0200 [App/0]      ERR    at io.gearpump.services.MasterService$.submitAndDeleteTempFiles(MasterService.scala:269)
2016-06-06T16:20:58.24+0200 [App/0]      ERR    at io.gearpump.services.MasterService$.submitGearApp(MasterService.scala:227)
2016-06-06T16:20:58.24+0200 [App/0]      ERR    at io.gearpump.services.MasterService$$anonfun$doRoute$1$$anonfun$apply$46$$anonfun$apply$47$$anonfun$apply$48$$anonfun$apply$49$$anonfun$apply$1.apply$mcZ$sp(MasterService.scala:126)
2016-06-06T16:20:58.24+0200 [App/0]      ERR    at io.gearpump.services.MasterService$$anonfun$doRoute$1$$anonfun$apply$46$$anonfun$apply$47$$anonfun$apply$48$$anonfun$apply$49$$anonfun$apply$1.apply(MasterService.scala:126)
2016-06-06T16:20:58.24+0200 [App/0]      ERR    at io.gearpump.services.MasterService$$anonfun$doRoute$1$$anonfun$apply$46$$anonfun$apply$47$$anonfun$apply$48$$anonfun$apply$49$$anonfun$apply$1.apply(MasterService.scala:126)
2016-06-06T16:20:58.24+0200 [App/0]      ERR    at scala.concurrent.impl.Future$PromiseCompletingRunnable.liftedTree1$1(Future.scala:24)
2016-06-06T16:20:58.24+0200 [App/0]      ERR    at scala.concurrent.impl.Future$PromiseCompletingRunnable.run(Future.scala:24)
2016-06-06T16:20:58.24+0200 [App/0]      ERR    at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:39)
2016-06-06T16:20:58.24+0200 [App/0]      ERR    at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(AbstractDispatcher.scala:405)
2016-06-06T16:20:58.24+0200 [App/0]      ERR    at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
2016-06-06T16:20:58.24+0200 [App/0]      ERR    at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
2016-06-06T16:20:58.24+0200 [App/0]      ERR    at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
2016-06-06T16:20:58.24+0200 [App/0]      ERR    at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)
{code}


This response:
* seems to be constructed from the second part of the log
* doesn't show "the real" cause of the error (exception in main), although the exception is
logged by the dashboard (see first part)
* contains entries both from info and error levels 

The response should be less noisy. 

We should either give the user/developer a way to implicitly exit with a message (that would
be passed as a response) or make the response more structured (for example the response could
have "error" and "info" field).



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message