SocketTimeoutException for DFP updateOrder

89 views
Skip to first unread message

maxbo...@gmail.com

unread,
Mar 21, 2016, 2:01:34 PM3/21/16
to Google's DoubleClick for Publishers API Forum
Hi, 

We facing issues with DFP api to update/get Orders/Lineitems. See lots of SocketTimeouts.
Network: 7175

Kindly help as soon as possbile
 
Adding dump 




java.net.SocketTimeoutException: Read timed out
        at org.apache.axis.AxisFault.makeFault(AxisFault.java:101)
        at org.apache.axis.transport.http.HTTPSender.invoke(HTTPSender.java:154)
        at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32)
        at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118)
        at org.apache.axis.SimpleChain.invoke(SimpleChain.java:83)
        at org.apache.axis.client.AxisClient.invoke(AxisClient.java:165)
        at org.apache.axis.client.Call.invokeEngine(Call.java:2784)
        at org.apache.axis.client.Call.invoke(Call.java:2767)
        at org.apache.axis.client.Call.invoke(Call.java:2443)
        at org.apache.axis.client.Call.invoke(Call.java:2366)
        at org.apache.axis.client.Call.invoke(Call.java:1812)
        at com.google.api.ads.dfp.axis.v201508.OrderServiceSoapBindingStub.updateOrders(OrderServiceSoapBindingStub.java:1556)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:497)
        at com.google.api.ads.common.lib.soap.SoapClientHandler.invoke(SoapClientHandler.java:109)
        at com.google.api.ads.common.lib.soap.axis.AxisHandler.invokeSoapCall(AxisHandler.java:230)
        at com.google.api.ads.common.lib.soap.SoapServiceClient.callSoapClient(SoapServiceClient.java:62)
        at com.google.api.ads.common.lib.soap.SoapServiceClient.invoke(SoapServiceClient.java:92)
        at com.sun.proxy.$Proxy14.updateOrders(Unknown Source)
        at com.ssf5.tcpm.TCPMV2.T_Order.saveOrders(T_Order.java:852)
        at com.ssf5.tcpm.TCPMV2.T_Order$1.call(T_Order.java:534)
        at com.ssf5.tcpm.TCPMV2.T_Order$1.call(T_Order.java:530)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.SocketTimeoutException: Read timed out
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:170)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
        at sun.security.ssl.InputRecord.read(InputRecord.java:503)
        at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973)
        at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930)
        at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
        at org.apache.axis.transport.http.HTTPSender.readHeadersFromSocket(HTTPSender.java:583)
        at org.apache.axis.transport.http.HTTPSender.invoke(HTTPSender.java:143)

maxbo...@gmail.com

unread,
Mar 21, 2016, 2:18:04 PM3/21/16
to Google's DoubleClick for Publishers API Forum
Here is the dump for lineitem update as well

SEVERE: null
AxisFault
 faultSubcode:
 faultString: java.net.SocketTimeoutException: Read timed out
 faultActor:
 faultNode:
 faultDetail:
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:170)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at sun.security.ssl.InputRecord.readFully(InputRecord.java:465)
        at sun.security.ssl.InputRecord.read(InputRecord.java:503)
        at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973)
        at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930)
        at sun.security.ssl.AppInputStream.read(AppInputStream.java:105)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
        at org.apache.axis.transport.http.HTTPSender.readHeadersFromSocket(HTTPSender.java:583)
        at org.apache.axis.transport.http.HTTPSender.invoke(HTTPSender.java:143)
        at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32)
        at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118)
        at org.apache.axis.SimpleChain.invoke(SimpleChain.java:83)
        at org.apache.axis.client.AxisClient.invoke(AxisClient.java:165)
        at org.apache.axis.client.Call.invokeEngine(Call.java:2784)
        at org.apache.axis.client.Call.invoke(Call.java:2767)
        at org.apache.axis.client.Call.invoke(Call.java:2443)
        at org.apache.axis.client.Call.invoke(Call.java:2366)
        at org.apache.axis.client.Call.invoke(Call.java:1812)
        at com.google.api.ads.dfp.axis.v201508.LineItemServiceSoapBindingStub.updateLineItems(LineItemServiceSoapBindingStub.java:2048)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:497)
        at com.google.api.ads.common.lib.soap.SoapClientHandler.invoke(SoapClientHandler.java:109)
        at com.google.api.ads.common.lib.soap.axis.AxisHandler.invokeSoapCall(AxisHandler.java:230)
        at com.google.api.ads.common.lib.soap.SoapServiceClient.callSoapClient(SoapServiceClient.java:62)
        at com.google.api.ads.common.lib.soap.SoapServiceClient.invoke(SoapServiceClient.java:92)
        at com.sun.proxy.$Proxy15.updateLineItems(Unknown Source)
        at com.ssf5.tcpm.TCPMV2.T_LineItem.saveLineItems(T_LineItem.java:870)
        at com.ssf5.tcpm.TCPMV2.T_LineItem.processLineItemRunningONLive(T_LineItem.java:530)
        at com.ssf5.tcpm.TCPMV2.T_LineItem.start(T_LineItem.java:145)
        at com.ssf5.tcpm.TCPMV2.T_Order$2.call(T_Order.java:554)
        at com.ssf5.tcpm.TCPMV2.T_Order$2.call(T_Order.java:544)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

Tesfamichael Hailegeorgis(DFP API Team)

unread,
Mar 21, 2016, 3:35:52 PM3/21/16
to Google's DoubleClick for Publishers API Forum
Hi,

I am able to pull all the orders(2801) and all line items for your network code(7175) without any issue. Is this still happening consistently or intermittently? Does retrying the request succeed?

Thanks,
Tesfamichael Hailegeorgis, DFP API Team

maxbo...@gmail.com

unread,
Mar 22, 2016, 7:59:25 AM3/22/16
to Google's DoubleClick for Publishers API Forum
Hi,

The issue not with pulling but the update(push). Analyse the DUMP added. It has call to updateOrders / updateLineitems.

Tesfamichael Hailegeorgis(DFP API Team)

unread,
Mar 22, 2016, 11:47:40 AM3/22/16
to Google's DoubleClick for Publishers API Forum
Hi,

Thanks for replying :)

Just to confirm, in your original post you said  "We facing issues with DFP api to update/get Orders/Lineitems. See lots of SocketTimeouts." That's why I was checking the order service and line item service calls for your network.
 
To get to the bottom of this ASAP, I'd like to clarify:

  1. Is this happening consistently or intermittently? If it is happening intermittently, does retrying the request succeed?
  2. Is it happening only for these services or are you able to update other entities like users, ad units or proposals line items? I'm asking this to make sure this issue is not related to your network or firewall setting and if it is specific to the order service and line item service. The stack trace doesn't provide this information.
  3. If this is happening consistently, can you provide the request/response SOAP logs? The logs will help me attempt to recreate the issue on my end and investigate the root cause. Unfortunately, the stack trace doesn't show the request parameters.
if you haven't enable the logging yet, please follow the instructions in the README file under 'How do I enable logging?' section.

Thanks,
Tesfamichael Hailegeorgis, DFP API Team

maxbo...@gmail.com

unread,
Mar 22, 2016, 11:15:30 PM3/22/16
to Google's DoubleClick for Publishers API Forum
Hello,

1. The issue is intermittently. Specially it happens when there is update batch is 200 or more for Orders/Lintitems.
2. We use lineitem and order service in our application not any other
3. We do retry in cases of failure but the turn around time becomes really high. In total it goes for more than 60-140 mins which i presume should not be. 

Attaching our custom logs of lineitem update service call. It has Count and TimeTakenSecs data points which indicates the response time.



/var/log/ai/aiV2.log:11087:INFO: Into saveLineItems..... LineItemService.updateLineItems End. Count: 60, TimeTakenSecs: 17
/var/log/ai/aiV2.log-11088-Mar 22, 2016 11:56:21 AM com.ssf5.aiV2.T_LineItem saveLineItems
--
/var/log/ai/aiV2.log:11127:INFO: Into saveLineItems..... LineItemService.updateLineItems End. Count: 1, TimeTakenSecs: 0
/var/log/ai/aiV2.log-11128-Mar 22, 2016 11:56:22 AM com.ssf5.aiV2.T_LineItem saveLineItems
--
/var/log/ai/aiV2.log:21333:INFO: Into saveLineItems..... LineItemService.updateLineItems End. Count: 31, TimeTakenSecs: 5
/var/log/ai/aiV2.log-21334-Mar 22, 2016 11:57:23 AM com.ssf5.aiV2.T_LineItem saveLineItems
--
/var/log/ai/aiV2.log:45785:INFO: Into saveLineItems..... LineItemService.updateLineItems End. Count: 311, TimeTakenSecs: 230
/var/log/ai/aiV2.log-45786-Mar 22, 2016 12:03:01 PM com.ssf5.aiV2.T_LineItem saveLineItems
--
/var/log/ai/aiV2.log:65427:INFO: Into saveLineItems..... LineItemService.updateLineItems End. Count: 259, TimeTakenSecs: 157
/var/log/ai/aiV2.log-65428-Mar 22, 2016 12:06:12 PM com.ssf5.aiV2.T_LineItem saveLineItems
--
/var/log/ai/aiV2.log:75048:INFO: Into saveLineItems..... LineItemService.updateLineItems End. Count: 397, TimeTakenSecs: 1001
/var/log/ai/aiV2.log-75049-Mar 22, 2016 12:23:07 PM com.ssf5.aiV2.T_LineItem saveLineItems
--
/var/log/ai/aiV2.log:76804:INFO: Into saveLineItems..... LineItemService.updateLineItems End. Count: 153, TimeTakenSecs: 20
/var/log/ai/aiV2.log-76805-Mar 22, 2016 12:23:35 PM com.ssf5.aiV2.T_LineItem saveLineItems
--
/var/log/ai/aiV2.log:87697:INFO: Into saveLineItems..... LineItemService.updateLineItems End. Count: 60, TimeTakenSecs: 16
/var/log/ai/aiV2.log-87698-Mar 22, 2016 12:30:32 PM com.ssf5.aiV2.T_LineItem saveLineItems
--
/var/log/ai/aiV2.log:97913:INFO: Into saveLineItems..... LineItemService.updateLineItems End. Count: 31, TimeTakenSecs: 5
/var/log/ai/aiV2.log-97914-Mar 22, 2016 12:31:56 PM com.ssf5.aiV2.T_LineItem saveLineItems
--
/var/log/ai/aiV2.log:122085:INFO: Into saveLineItems..... LineItemService.updateLineItems End. Count: 310, TimeTakenSecs: 150
/var/log/ai/aiV2.log-122086-Mar 22, 2016 12:35:59 PM com.ssf5.aiV2.T_LineItem saveLineItems
--
/var/log/ai/aiV2.log:141435:INFO: Into saveLineItems..... LineItemService.updateLineItems End. Count: 259, TimeTakenSecs: 101
/var/log/ai/aiV2.log-141436-Mar 22, 2016 12:38:10 PM com.ssf5.aiV2.T_LineItem saveLineItems
--
/var/log/ai/aiV2.log:149781:INFO: Into saveLineItems..... LineItemService.updateLineItems End. Count: 265, TimeTakenSecs: 337
/var/log/ai/aiV2.log-149782-Mar 22, 2016 12:44:00 PM com.ssf5.aiV2.T_LineItem saveLineItems
--
/var/log/ai/aiV2.log:152613:INFO: Into saveLineItems..... LineItemService.updateLineItems End. Count: 42, TimeTakenSecs: 10
/var/log/ai/aiV2.log-152614-Mar 22, 2016 12:44:15 PM com.ssf5.aiV2.T_LineItem saveLineItems

maxbo...@gmail.com

unread,
Mar 22, 2016, 11:32:03 PM3/22/16
to Google's DoubleClick for Publishers API Forum
Hi,

Another point just came to me. Let me brief

1. We read the order/lineitem 
2. create a copy of the object read.
3. Apply changes to the object.
4. Update object back 

Can i use hashcode to identify any change in object. This might reduce the batch size to update.

Tesfamichael Hailegeorgis(DFP API Team)

unread,
Mar 23, 2016, 1:55:37 PM3/23/16
to Google's DoubleClick for Publishers API Forum
Hi,

Generally, we recommend to implement the appropriate retry logic if this is an intermittent issue as you have confirmed.

Thanks,
Tesfamichael Hailegeorgis, DFP API Team

max bounty

unread,
Mar 23, 2016, 2:19:43 PM3/23/16
to Tesfamichael Hailegeorgis, Google's DoubleClick for Publishers API Forum
Hi,

Thanks. 

My another question to this was regarding the response time of update service.
It is generally around 1000 secs for the batch of 250-400. See custom logs.

--
You received this message because you are subscribed to a topic in the Google Groups "Google's DoubleClick for Publishers API Forum" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/google-doubleclick-for-publishers-api/fuxHXjDVmGk/unsubscribe.
To unsubscribe from this group and all its topics, send an email to google-doubleclick-for-p...@googlegroups.com.
To post to this group, send email to google-doubleclick...@googlegroups.com.
Visit this group at https://groups.google.com/group/google-doubleclick-for-publishers-api.
For more options, visit https://groups.google.com/d/optout.

Tesfamichael Hailegeorgis(DFP API Team)

unread,
Mar 23, 2016, 5:00:11 PM3/23/16
to Google's DoubleClick for Publishers API Forum, dfpapi-adviso...@google.com
Hi,

Thanks for the reply.

You might want to decrease the size of the request batch to increase the response time. I don't have enough information as to how big the line item objects are, since I don't have the request SOAP log. You probably have a lot of targeting objects set on the line items, that could be the potential reason for it to be slow or timeout.

Thanks,
Tesfamichael Hailegeorgis, DFP API Team

On Wednesday, March 23, 2016 at 2:19:43 PM UTC-4, max bounty wrote:
Hi,

Thanks. 

My another question to this was regarding the response time of update service.
It is generally around 1000 secs for the batch of 250-400. See custom logs.
To unsubscribe from this group and all its topics, send an email to google-doubleclick-for-publishers-api+unsubscribe@googlegroups.com.
To post to this group, send email to google-doubleclick-for-publishers-api@googlegroups.com.
Reply all
Reply to author
Forward
0 new messages